[==========] 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:14.767940 32395 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.162.254:38453
I20260812 06:17:14.769134 32395 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:14.769767 32395 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:14.777482 32411 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:14.777482 32406 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:14.777683 32395 server_base.cc:1061] running on GCE node
W20260812 06:17:14.777773 32405 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:14.778412 32395 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:14.778513 32395 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:14.778597 32395 hybrid_clock.cc:648] HybridClock initialized: now 1786515434778586 us; error 0 us; skew 500 ppm
I20260812 06:17:14.780916 32395 webserver.cc:533] Webserver started at http://127.31.162.254:37327/ using document root <none> and password file <none>
I20260812 06:17:14.781533 32395 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:14.781647 32395 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:14.781939 32395 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:14.783775 32395 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/master-0-root/instance:
uuid: "b3b2408d14804224b94335a7b627ca45"
format_stamp: "Formatted at 2026-08-12 06:17:14 on dist-test-slave-kvfs"
I20260812 06:17:14.788254 32395 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.001s	sys 0.003s
I20260812 06:17:14.791226 32418 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:14.792717 32395 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:14.792860 32395 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/master-0-root
uuid: "b3b2408d14804224b94335a7b627ca45"
format_stamp: "Formatted at 2026-08-12 06:17:14 on dist-test-slave-kvfs"
I20260812 06:17:14.793026 32395 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-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:14.814533 32395 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:14.815286 32395 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:14.815472 32395 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:14.824832 32395 rpc_server.cc:307] RPC server started. Bound to: 127.31.162.254:38453
I20260812 06:17:14.824860 32498 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.162.254:38453 every 8 connection(s)
I20260812 06:17:14.827342 32499 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:14.834431 32499 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45: Bootstrap starting.
I20260812 06:17:14.837026 32499 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:14.838006 32499 log.cc:826] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:14.840921 32499 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45: No bootstrap required, opened a new log
I20260812 06:17:14.844767 32499 raft_consensus.cc:359] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3b2408d14804224b94335a7b627ca45" member_type: VOTER }
I20260812 06:17:14.845027 32499 raft_consensus.cc:385] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:14.845077 32499 raft_consensus.cc:740] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b3b2408d14804224b94335a7b627ca45, State: Initialized, Role: FOLLOWER
I20260812 06:17:14.845822 32499 consensus_queue.cc:260] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [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: "b3b2408d14804224b94335a7b627ca45" member_type: VOTER }
I20260812 06:17:14.846007 32499 raft_consensus.cc:399] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:14.846058 32499 raft_consensus.cc:493] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:14.846153 32499 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:14.847102 32499 raft_consensus.cc:515] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3b2408d14804224b94335a7b627ca45" member_type: VOTER }
I20260812 06:17:14.847616 32499 leader_election.cc:304] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [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: b3b2408d14804224b94335a7b627ca45; no voters: 
I20260812 06:17:14.848043 32499 leader_election.cc:290] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:14.848547 32502 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:14.848835 32502 raft_consensus.cc:697] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 1 LEADER]: Becoming Leader. State: Replica: b3b2408d14804224b94335a7b627ca45, State: Running, Role: LEADER
I20260812 06:17:14.849277 32499 sys_catalog.cc:565] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:14.849416 32502 consensus_queue.cc:237] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [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: "b3b2408d14804224b94335a7b627ca45" member_type: VOTER }
I20260812 06:17:14.851807 32503 sys_catalog.cc:455] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b3b2408d14804224b94335a7b627ca45" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3b2408d14804224b94335a7b627ca45" member_type: VOTER } }
I20260812 06:17:14.851861 32504 sys_catalog.cc:455] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b3b2408d14804224b94335a7b627ca45. Latest consensus state: current_term: 1 leader_uuid: "b3b2408d14804224b94335a7b627ca45" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3b2408d14804224b94335a7b627ca45" member_type: VOTER } }
I20260812 06:17:14.851963 32503 sys_catalog.cc:458] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:14.852003 32395 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:14.851970 32504 sys_catalog.cc:458] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [sys.catalog]: This master's current role is: LEADER
W20260812 06:17:14.855020 32524 catalog_manager.cc:1594] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:14.855163 32524 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:14.855288 32526 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:14.856657 32526 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:14.864300 32526 catalog_manager.cc:1383] Generated new cluster ID: 00ad13b16a114138ac87d77cf75c524a
I20260812 06:17:14.864446 32526 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:14.879088 32526 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:14.880199 32526 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:14.892488 32526 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45: Generated new TSK 0
I20260812 06:17:14.893332 32526 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:14.917914 32395 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:14.921864 32533 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:14.922107 32532 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:14.922179 32536 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:14.922374 32395 server_base.cc:1061] running on GCE node
I20260812 06:17:14.922628 32395 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:14.922678 32395 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:14.922701 32395 hybrid_clock.cc:648] HybridClock initialized: now 1786515434922701 us; error 0 us; skew 500 ppm
I20260812 06:17:14.923808 32395 webserver.cc:533] Webserver started at http://127.31.162.193:36017/ using document root <none> and password file <none>
I20260812 06:17:14.923992 32395 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:14.924082 32395 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:14.924162 32395 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:14.924654 32395 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/instance:
uuid: "6c7a065483d04ca4aee6e32cb1eabb62"
format_stamp: "Formatted at 2026-08-12 06:17:14 on dist-test-slave-kvfs"
I20260812 06:17:14.926661 32395 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:14.927997 32544 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:14.928400 32395 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:14.928486 32395 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root
uuid: "6c7a065483d04ca4aee6e32cb1eabb62"
format_stamp: "Formatted at 2026-08-12 06:17:14 on dist-test-slave-kvfs"
I20260812 06:17:14.928570 32395 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-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:14.943198 32395 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:14.943768 32395 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:14.944463 32395 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:14.945480 32395 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:14.945540 32395 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:14.945647 32395 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:14.945678 32395 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:14.953565 32395 rpc_server.cc:307] RPC server started. Bound to: 127.31.162.193:44341
I20260812 06:17:14.953603 32655 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.162.193:44341 every 8 connection(s)
I20260812 06:17:14.967599 32658 heartbeater.cc:344] Connected to a master server at 127.31.162.254:38453
I20260812 06:17:14.967923 32658 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:14.968503 32658 heartbeater.cc:507] Master 127.31.162.254:38453 requested a full tablet report, sending...
I20260812 06:17:14.970144 32440 ts_manager.cc:194] Registered new tserver with Master: 6c7a065483d04ca4aee6e32cb1eabb62 (127.31.162.193:44341)
I20260812 06:17:14.971081 32395 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016363686s
I20260812 06:17:14.971462 32440 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60258
I20260812 06:17:14.984757 32440 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60266:
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:15.000833 32595 tablet_service.cc:1511] Processing CreateTablet for tablet df1aa1f7403249e7bd6c6fd5dd0cb855 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6e637279d22a44a59023156609da398b]), partition=
I20260812 06:17:15.001365 32595 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet df1aa1f7403249e7bd6c6fd5dd0cb855. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:15.004043 32672 tablet_bootstrap.cc:492] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Bootstrap starting.
I20260812 06:17:15.005369 32672 tablet_bootstrap.cc:654] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:15.006834 32672 tablet_bootstrap.cc:492] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: No bootstrap required, opened a new log
I20260812 06:17:15.006989 32672 ts_tablet_manager.cc:1403] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:15.007529 32672 raft_consensus.cc:359] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c7a065483d04ca4aee6e32cb1eabb62" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 44341 } }
I20260812 06:17:15.007678 32672 raft_consensus.cc:385] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:15.007727 32672 raft_consensus.cc:740] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6c7a065483d04ca4aee6e32cb1eabb62, State: Initialized, Role: FOLLOWER
I20260812 06:17:15.007927 32672 consensus_queue.cc:260] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [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: "6c7a065483d04ca4aee6e32cb1eabb62" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 44341 } }
I20260812 06:17:15.008083 32672 raft_consensus.cc:399] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:15.008136 32672 raft_consensus.cc:493] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:15.008190 32672 raft_consensus.cc:3060] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:15.009001 32672 raft_consensus.cc:515] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c7a065483d04ca4aee6e32cb1eabb62" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 44341 } }
I20260812 06:17:15.009172 32672 leader_election.cc:304] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [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: 6c7a065483d04ca4aee6e32cb1eabb62; no voters: 
I20260812 06:17:15.009413 32672 leader_election.cc:290] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:15.009831 32672 ts_tablet_manager.cc:1434] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:15.010113 32675 raft_consensus.cc:2804] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:15.010179 32658 heartbeater.cc:499] Master 127.31.162.254:38453 was elected leader, sending a full tablet report...
I20260812 06:17:15.011161 32675 raft_consensus.cc:697] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 1 LEADER]: Becoming Leader. State: Replica: 6c7a065483d04ca4aee6e32cb1eabb62, State: Running, Role: LEADER
I20260812 06:17:15.011384 32675 consensus_queue.cc:237] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [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: "6c7a065483d04ca4aee6e32cb1eabb62" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 44341 } }
I20260812 06:17:15.015530 32440 catalog_manager.cc:5719] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6c7a065483d04ca4aee6e32cb1eabb62 (127.31.162.193). New cstate: current_term: 1 leader_uuid: "6c7a065483d04ca4aee6e32cb1eabb62" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c7a065483d04ca4aee6e32cb1eabb62" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 44341 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:15.092787 32395 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.068s	user 0.026s	sys 0.010s
I20260812 06:17:15.205299 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushMRSOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=15.086190
I20260812 06:17:15.366315 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushMRSOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.161s	user 0.130s	sys 0.024s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":293,"delete_count":0,"dirs.queue_time_us":758,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":825,"drs_written":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36618,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":104,"threads_started":1,"update_count":1000}
I20260812 06:17:15.367743 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling LogGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855): free 8725963 bytes of WAL
I20260812 06:17:15.368211 32551 log_reader.cc:385] T df1aa1f7403249e7bd6c6fd5dd0cb855: removed 1 log segments from log reader
I20260812 06:17:15.368299 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000001 (ops 1-6)
I20260812 06:17:15.370956 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: LogGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:15.371621 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling UndoDeltaBlockGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855): 12308958 bytes on disk
I20260812 06:17:15.372486 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: UndoDeltaBlockGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":139,"lbm_reads_lt_1ms":4}
I20260812 06:17:15.373080 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:15.396924 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.024s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.398114 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:15.530799 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.132s	user 0.094s	sys 0.036s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528900,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":524,"lbm_read_time_us":8824,"lbm_reads_lt_1ms":360,"lbm_write_time_us":23565,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":268,"threads_started":5,"update_count":1500}
I20260812 06:17:15.531494 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:15.576517 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.045s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19204,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.577154 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:15.692481 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.115s	user 0.095s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":290,"lbm_read_time_us":6549,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22512,"lbm_writes_lt_1ms":343,"mutex_wait_us":43,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":1500}
I20260812 06:17:15.693214 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:15.727387 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.034s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13636,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.727970 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:15.845927 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.118s	user 0.089s	sys 0.025s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528782,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":146,"lbm_read_time_us":7914,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21889,"lbm_writes_lt_1ms":343,"mutex_wait_us":71,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":1500}
I20260812 06:17:15.846684 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:15.897348 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.050s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18885,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.898082 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:15.911037 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4724,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.911762 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:16.066910 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.155s	user 0.131s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":555,"lbm_read_time_us":10961,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30916,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:17:16.067711 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:16.128921 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.061s	user 0.033s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":22136,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.129582 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:16.141340 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4558,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.141923 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:16.308264 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.166s	user 0.122s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":11647,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28311,"lbm_writes_lt_1ms":443,"mutex_wait_us":17,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:17:16.308920 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:16.360363 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.051s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16972,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.361023 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:16.373266 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.373750 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:16.511231 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.137s	user 0.120s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1629,"lbm_read_time_us":8775,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29215,"lbm_writes_lt_1ms":443,"mutex_wait_us":486,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:16.512079 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:16.560365 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.048s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16853,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.561015 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:16.572810 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.012s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.574115 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:16.702061 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.128s	user 0.087s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":498,"lbm_read_time_us":8124,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24342,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:17:16.702737 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:16.758291 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.055s	user 0.022s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20464,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.759173 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:16.777742 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.018s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.778390 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushMRSOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:16.819212 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushMRSOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.041s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":290,"dirs.run_wall_time_us":1510,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1633,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:16.820230 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling LogGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855): free 123804183 bytes of WAL
I20260812 06:17:16.820506 32551 log_reader.cc:385] T df1aa1f7403249e7bd6c6fd5dd0cb855: removed 12 log segments from log reader
I20260812 06:17:16.820551 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000002 (ops 7-11)
I20260812 06:17:16.820582 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000003 (ops 12-16)
I20260812 06:17:16.820655 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000004 (ops 17-21)
I20260812 06:17:16.820701 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000005 (ops 22-26)
I20260812 06:17:16.820758 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000006 (ops 27-30)
I20260812 06:17:16.820811 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000007 (ops 31-35)
I20260812 06:17:16.820845 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000008 (ops 36-40)
I20260812 06:17:16.820883 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000009 (ops 41-45)
I20260812 06:17:16.820921 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000010 (ops 46-50)
I20260812 06:17:16.820958 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000011 (ops 51-55)
I20260812 06:17:16.821002 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000012 (ops 56-60)
I20260812 06:17:16.821040 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000013 (ops 61-64)
I20260812 06:17:16.849181 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: LogGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:16.849783 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling UndoDeltaBlockGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855): 462 bytes on disk
I20260812 06:17:16.850373 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: UndoDeltaBlockGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:16.851123 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:16.867046 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4969,"lbm_writes_lt_1ms":103,"mutex_wait_us":3,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.867551 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:16.879045 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4305,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.879671 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:17.110309 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.230s	user 0.147s	sys 0.083s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":716,"lbm_read_time_us":14308,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39010,"lbm_writes_lt_1ms":643,"mutex_wait_us":76,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22656,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:17:17.111157 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=14.095187
I20260812 06:17:17.178612 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.067s	user 0.037s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25809,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.179379 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:17.192412 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.193070 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:17.390297 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.195s	user 0.124s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":962,"lbm_read_time_us":12267,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34568,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29568,"update_count":2500}
I20260812 06:17:17.391124 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=14.095187
I20260812 06:17:17.463588 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.072s	user 0.029s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28459,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.464358 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:17.482532 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.018s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.483218 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:17.668083 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.185s	user 0.131s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":435,"lbm_read_time_us":12742,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32162,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":72192,"update_count":2500}
I20260812 06:17:17.668700 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=11.118625
I20260812 06:17:17.716962 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.048s	user 0.023s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":21318,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:17.717521 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:17.736788 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.019s	user 0.005s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6882,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:17.737413 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:17.909919 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.172s	user 0.126s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":771,"lbm_read_time_us":10506,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28721,"lbm_writes_lt_1ms":443,"mutex_wait_us":323,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.910430 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=11.118625
I20260812 06:17:17.950125 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.039s	user 0.014s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16717,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:17.952607 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:17.968443 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5394,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:17.969182 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:18.110248 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.141s	user 0.130s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":8721,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28077,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2000}
I20260812 06:17:18.110903 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:18.151643 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.041s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17587,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:18.152314 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:18.165778 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4765,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.166659 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:18.302472 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.136s	user 0.107s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":612,"lbm_read_time_us":9228,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25103,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:17:18.303256 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:18.357507 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.054s	user 0.023s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16375,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:18.358413 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:18.378394 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.379176 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushMRSOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:18.430224 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushMRSOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.051s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":177,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":2111,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1826,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:18.431267 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling LogGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855): free 121006434 bytes of WAL
I20260812 06:17:18.431573 32551 log_reader.cc:385] T df1aa1f7403249e7bd6c6fd5dd0cb855: removed 12 log segments from log reader
I20260812 06:17:18.431648 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000014 (ops 65-69)
I20260812 06:17:18.431705 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000015 (ops 70-74)
I20260812 06:17:18.431764 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000016 (ops 75-79)
I20260812 06:17:18.431809 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000017 (ops 80-84)
I20260812 06:17:18.431849 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000018 (ops 85-88)
I20260812 06:17:18.431885 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000019 (ops 89-93)
I20260812 06:17:18.431926 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000020 (ops 94-98)
I20260812 06:17:18.431965 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000021 (ops 99-103)
I20260812 06:17:18.432004 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000022 (ops 104-108)
I20260812 06:17:18.432082 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000023 (ops 109-113)
I20260812 06:17:18.432123 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000024 (ops 114-118)
I20260812 06:17:18.432163 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000025 (ops 119-123)
I20260812 06:17:18.459120 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: LogGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:18.459765 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=3.181125
I20260812 06:17:18.484191 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.024s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5461,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:18.484761 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:18.500308 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5872,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:18.501021 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:18.723642 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.222s	user 0.169s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":463,"lbm_read_time_us":13377,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37064,"lbm_writes_lt_1ms":643,"mutex_wait_us":69,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20096,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:17:18.725489 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling UndoDeltaBlockGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855): 448 bytes on disk
I20260812 06:17:18.726197 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: UndoDeltaBlockGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:17:18.726886 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=14.095187
I20260812 06:17:18.773057 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.046s	user 0.024s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20715,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.773670 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:18.947108 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.173s	user 0.119s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631194,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":886,"lbm_read_time_us":12005,"lbm_reads_lt_1ms":467,"lbm_write_time_us":29355,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:17:18.947810 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=11.118625
I20260812 06:17:18.992738 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.045s	user 0.037s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19326,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:18.993559 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:19.007284 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4846,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:19.007894 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:19.154647 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.147s	user 0.112s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":9418,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28928,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":135808,"update_count":2000}
I20260812 06:17:19.155189 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:19.204813 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.049s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19546,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.205531 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:19.217731 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4304,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.218330 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:19.363467 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.145s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":781,"lbm_read_time_us":11419,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27651,"lbm_writes_lt_1ms":443,"mutex_wait_us":398,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:17:19.364346 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:19.407516 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.043s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19219,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.408108 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:19.420526 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.421226 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:19.565199 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.144s	user 0.100s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":89,"lbm_read_time_us":10198,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28826,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2000}
I20260812 06:17:19.566160 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:19.616834 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.050s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18080,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.617687 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:19.631078 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.631647 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:19.791589 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.160s	user 0.100s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":11615,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26180,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30848,"update_count":2000}
I20260812 06:17:19.792363 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:19.853906 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.061s	user 0.023s	sys 0.028s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":24437,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.855094 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:19.867800 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4515,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.868737 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:20.007655 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.139s	user 0.113s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":448,"lbm_read_time_us":8527,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29264,"lbm_writes_lt_1ms":443,"mutex_wait_us":111,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:17:20.008467 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:20.049103 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.040s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16643,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:20.049612 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushMRSOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:20.110826 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushMRSOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.061s	user 0.035s	sys 0.004s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":119,"dirs.run_cpu_time_us":302,"dirs.run_wall_time_us":1580,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3186,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:20.111603 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling LogGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855): free 120100558 bytes of WAL
I20260812 06:17:20.111851 32551 log_reader.cc:385] T df1aa1f7403249e7bd6c6fd5dd0cb855: removed 12 log segments from log reader
I20260812 06:17:20.111896 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000026 (ops 124-128)
I20260812 06:17:20.111925 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000027 (ops 129-133)
I20260812 06:17:20.111991 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000028 (ops 134-138)
I20260812 06:17:20.112059 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000029 (ops 139-142)
I20260812 06:17:20.112102 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000030 (ops 143-147)
I20260812 06:17:20.112121 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000031 (ops 148-152)
I20260812 06:17:20.112161 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000032 (ops 153-157)
I20260812 06:17:20.112205 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000033 (ops 158-162)
I20260812 06:17:20.112243 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000034 (ops 163-166)
I20260812 06:17:20.112282 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000035 (ops 167-171)
I20260812 06:17:20.112319 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000036 (ops 172-176)
I20260812 06:17:20.112358 32551 log.cc:1079] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/df1aa1f7403249e7bd6c6fd5dd0cb855/wal-000000037 (ops 177-180)
I20260812 06:17:20.140497 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: LogGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:20.141213 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling UndoDeltaBlockGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855): 473 bytes on disk
I20260812 06:17:20.141809 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: UndoDeltaBlockGCOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:17:20.142918 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=7.149875
I20260812 06:17:20.165905 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.022s	user 0.010s	sys 0.010s Metrics: {"bytes_written":8533272,"delete_count":0,"lbm_write_time_us":9540,"lbm_writes_lt_1ms":211,"reinsert_count":0,"update_count":1040}
I20260812 06:17:20.166736 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:20.188476 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3774458,"delete_count":0,"lbm_write_time_us":5939,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:17:20.189117 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:20.380513 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.191s	user 0.153s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836251,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":366,"lbm_read_time_us":13216,"lbm_reads_lt_1ms":665,"lbm_write_time_us":35860,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13696,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:17:20.381488 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=14.095187
I20260812 06:17:20.435740 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.053s	user 0.018s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23543,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.436504 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=2.188937
I20260812 06:17:20.456607 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.020s	user 0.017s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.457532 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=1.000000
I20260812 06:17:20.576507 32395 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.484s	user 2.004s	sys 0.166s
I20260812 06:17:20.622018 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: MajorDeltaCompactionOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.164s	user 0.115s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":9244,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32278,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:20.622742 32660 maintenance_manager.cc:419] P 6c7a065483d04ca4aee6e32cb1eabb62: Scheduling FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855): perf score=10.126437
I20260812 06:17:20.683768 32395 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.001s	sys 0.000s
I20260812 06:17:20.684598 32395 tablet_server.cc:179] TabletServer@127.31.162.193:0 shutting down...
I20260812 06:17:20.708928 32551 maintenance_manager.cc:643] P 6c7a065483d04ca4aee6e32cb1eabb62: FlushDeltaMemStoresOp(df1aa1f7403249e7bd6c6fd5dd0cb855) complete. Timing: real 0.086s	user 0.038s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20379,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:20.709789 32395 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:20.710276 32395 tablet_replica.cc:333] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62: stopping tablet replica
I20260812 06:17:20.710539 32395 raft_consensus.cc:2243] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:20.710809 32395 raft_consensus.cc:2272] T df1aa1f7403249e7bd6c6fd5dd0cb855 P 6c7a065483d04ca4aee6e32cb1eabb62 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:20.715996 32395 tablet_server.cc:196] TabletServer@127.31.162.193:0 shutdown complete.
I20260812 06:17:20.722056 32395 master.cc:562] Master@127.31.162.254:38453 shutting down...
I20260812 06:17:20.726229 32395 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:20.726507 32395 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:20.726619 32395 tablet_replica.cc:333] T 00000000000000000000000000000000 P b3b2408d14804224b94335a7b627ca45: stopping tablet replica
I20260812 06:17:20.739722 32395 master.cc:584] Master@127.31.162.254:38453 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6070 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:20.838028 32395 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.162.254:33577
I20260812 06:17:20.838449 32395 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:20.840905 32707 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:20.841033 32712 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:20.841150 32710 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:20.841033 32395 server_base.cc:1061] running on GCE node
I20260812 06:17:20.841468 32395 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:20.841526 32395 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:20.841542 32395 hybrid_clock.cc:648] HybridClock initialized: now 1786515440841542 us; error 0 us; skew 500 ppm
I20260812 06:17:20.842446 32395 webserver.cc:533] Webserver started at http://127.31.162.254:37365/ using document root <none> and password file <none>
I20260812 06:17:20.842615 32395 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:20.842664 32395 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:20.842720 32395 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:20.843086 32395 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/master-0-root/instance:
uuid: "40769b04dcd04ee7a5dd8bd1948d9d36"
format_stamp: "Formatted at 2026-08-12 06:17:20 on dist-test-slave-kvfs"
I20260812 06:17:20.844909 32395 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:20.845980 32718 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:20.846315 32395 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:20.846385 32395 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/master-0-root
uuid: "40769b04dcd04ee7a5dd8bd1948d9d36"
format_stamp: "Formatted at 2026-08-12 06:17:20 on dist-test-slave-kvfs"
I20260812 06:17:20.846491 32395 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-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:20.882560 32395 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:20.883068 32395 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:20.888213 32395 rpc_server.cc:307] RPC server started. Bound to: 127.31.162.254:33577
I20260812 06:17:20.898903   344 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.162.254:33577 every 8 connection(s)
I20260812 06:17:20.899312   346 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:20.906913   346 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36: Bootstrap starting.
I20260812 06:17:20.907804   346 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:20.909041   346 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36: No bootstrap required, opened a new log
I20260812 06:17:20.909461   346 raft_consensus.cc:359] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "40769b04dcd04ee7a5dd8bd1948d9d36" member_type: VOTER }
I20260812 06:17:20.909562   346 raft_consensus.cc:385] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:20.909586   346 raft_consensus.cc:740] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 40769b04dcd04ee7a5dd8bd1948d9d36, State: Initialized, Role: FOLLOWER
I20260812 06:17:20.909746   346 consensus_queue.cc:260] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [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: "40769b04dcd04ee7a5dd8bd1948d9d36" member_type: VOTER }
I20260812 06:17:20.909838   346 raft_consensus.cc:399] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:20.909864   346 raft_consensus.cc:493] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:20.909895   346 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:20.910660   346 raft_consensus.cc:515] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "40769b04dcd04ee7a5dd8bd1948d9d36" member_type: VOTER }
I20260812 06:17:20.910778   346 leader_election.cc:304] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [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: 40769b04dcd04ee7a5dd8bd1948d9d36; no voters: 
I20260812 06:17:20.910956   346 leader_election.cc:290] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:20.911177   355 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:20.911378   355 raft_consensus.cc:697] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 1 LEADER]: Becoming Leader. State: Replica: 40769b04dcd04ee7a5dd8bd1948d9d36, State: Running, Role: LEADER
I20260812 06:17:20.911517   346 sys_catalog.cc:565] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:20.911551   355 consensus_queue.cc:237] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [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: "40769b04dcd04ee7a5dd8bd1948d9d36" member_type: VOTER }
I20260812 06:17:20.912042   356 sys_catalog.cc:455] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "40769b04dcd04ee7a5dd8bd1948d9d36" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "40769b04dcd04ee7a5dd8bd1948d9d36" member_type: VOTER } }
I20260812 06:17:20.912047   357 sys_catalog.cc:455] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 40769b04dcd04ee7a5dd8bd1948d9d36. Latest consensus state: current_term: 1 leader_uuid: "40769b04dcd04ee7a5dd8bd1948d9d36" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "40769b04dcd04ee7a5dd8bd1948d9d36" member_type: VOTER } }
I20260812 06:17:20.912199   357 sys_catalog.cc:458] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:20.912436   356 sys_catalog.cc:458] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:20.913079   361 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:20.914203   361 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:20.914405 32395 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:20.916816   361 catalog_manager.cc:1383] Generated new cluster ID: 017dc5c3814e46319c4dbfa199a7bdb1
I20260812 06:17:20.916904   361 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:20.942049   361 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:20.942938   361 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:20.949682   361 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36: Generated new TSK 0
I20260812 06:17:20.949900   361 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:20.979396 32395 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:20.982471   387 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:20.982496 32395 server_base.cc:1061] running on GCE node
W20260812 06:17:20.982471   384 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:20.982501   382 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:20.983026 32395 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:20.983083 32395 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:20.983100 32395 hybrid_clock.cc:648] HybridClock initialized: now 1786515440983101 us; error 0 us; skew 500 ppm
I20260812 06:17:20.984148 32395 webserver.cc:533] Webserver started at http://127.31.162.193:35027/ using document root <none> and password file <none>
I20260812 06:17:20.984300 32395 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:20.984349 32395 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:20.984411 32395 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:20.984807 32395 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/instance:
uuid: "6c4e947993b54095b4f269847bc33d70"
format_stamp: "Formatted at 2026-08-12 06:17:20 on dist-test-slave-kvfs"
I20260812 06:17:20.986430 32395 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:20.987766   396 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:20.988348 32395 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:20.988440 32395 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root
uuid: "6c4e947993b54095b4f269847bc33d70"
format_stamp: "Formatted at 2026-08-12 06:17:20 on dist-test-slave-kvfs"
I20260812 06:17:20.988631 32395 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-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:20.996553 32395 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:20.997025 32395 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:20.997378 32395 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:20.997913 32395 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:20.997978 32395 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:20.998044 32395 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:20.998095 32395 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:21.004124 32395 rpc_server.cc:307] RPC server started. Bound to: 127.31.162.193:41521
I20260812 06:17:21.004734   500 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.162.193:41521 every 8 connection(s)
I20260812 06:17:21.014653   501 heartbeater.cc:344] Connected to a master server at 127.31.162.254:33577
I20260812 06:17:21.014788   501 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:21.015020   501 heartbeater.cc:507] Master 127.31.162.254:33577 requested a full tablet report, sending...
I20260812 06:17:21.015784 32745 ts_manager.cc:194] Registered new tserver with Master: 6c4e947993b54095b4f269847bc33d70 (127.31.162.193:41521)
I20260812 06:17:21.016309 32395 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011435178s
I20260812 06:17:21.016678 32745 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56448
I20260812 06:17:21.026340 32745 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56454:
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:21.037637   433 tablet_service.cc:1511] Processing CreateTablet for tablet c1107709dfff456e94c5d7bcb10b175e (DEFAULT_TABLE table=heavy-update-compaction-test [id=4e9db2b175694ed0bf053285bc37c658]), partition=
I20260812 06:17:21.038007   433 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c1107709dfff456e94c5d7bcb10b175e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:21.040755   520 tablet_bootstrap.cc:492] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Bootstrap starting.
I20260812 06:17:21.041803   520 tablet_bootstrap.cc:654] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:21.043370   520 tablet_bootstrap.cc:492] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: No bootstrap required, opened a new log
I20260812 06:17:21.043522   520 ts_tablet_manager.cc:1403] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:21.044087   520 raft_consensus.cc:359] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c4e947993b54095b4f269847bc33d70" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 41521 } }
I20260812 06:17:21.044225   520 raft_consensus.cc:385] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:21.044281   520 raft_consensus.cc:740] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6c4e947993b54095b4f269847bc33d70, State: Initialized, Role: FOLLOWER
I20260812 06:17:21.044446   520 consensus_queue.cc:260] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [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: "6c4e947993b54095b4f269847bc33d70" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 41521 } }
I20260812 06:17:21.044554   520 raft_consensus.cc:399] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:21.044605   520 raft_consensus.cc:493] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:21.044677   520 raft_consensus.cc:3060] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:21.045753   520 raft_consensus.cc:515] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c4e947993b54095b4f269847bc33d70" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 41521 } }
I20260812 06:17:21.045975   520 leader_election.cc:304] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [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: 6c4e947993b54095b4f269847bc33d70; no voters: 
I20260812 06:17:21.046561   520 leader_election.cc:290] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:21.046825   522 raft_consensus.cc:2804] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:21.047112   522 raft_consensus.cc:697] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 1 LEADER]: Becoming Leader. State: Replica: 6c4e947993b54095b4f269847bc33d70, State: Running, Role: LEADER
I20260812 06:17:21.047163   520 ts_tablet_manager.cc:1434] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Time spent starting tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:17:21.047277   501 heartbeater.cc:499] Master 127.31.162.254:33577 was elected leader, sending a full tablet report...
I20260812 06:17:21.047390   522 consensus_queue.cc:237] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [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: "6c4e947993b54095b4f269847bc33d70" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 41521 } }
I20260812 06:17:21.049000 32745 catalog_manager.cc:5719] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6c4e947993b54095b4f269847bc33d70 (127.31.162.193). New cstate: current_term: 1 leader_uuid: "6c4e947993b54095b4f269847bc33d70" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c4e947993b54095b4f269847bc33d70" member_type: VOTER last_known_addr { host: "127.31.162.193" port: 41521 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:21.114209 32395 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.014s	sys 0.009s
I20260812 06:17:21.255373   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushMRSOp(c1107709dfff456e94c5d7bcb10b175e): perf score=15.086190
I20260812 06:17:21.396641   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushMRSOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.141s	user 0.120s	sys 0.020s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":826,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36315,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1500}
I20260812 06:17:21.397403   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling LogGCOp(c1107709dfff456e94c5d7bcb10b175e): free 11976772 bytes of WAL
I20260812 06:17:21.397696   403 log_reader.cc:385] T c1107709dfff456e94c5d7bcb10b175e: removed 1 log segments from log reader
I20260812 06:17:21.397744   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000001 (ops 1-6)
I20260812 06:17:21.400411   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: LogGCOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:21.400799   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling UndoDeltaBlockGCOp(c1107709dfff456e94c5d7bcb10b175e): 12308960 bytes on disk
I20260812 06:17:21.401325   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: UndoDeltaBlockGCOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:21.401772   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:21.419787   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.018s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6078,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.420269   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:21.567131   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.147s	user 0.117s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":662,"lbm_read_time_us":9916,"lbm_reads_lt_1ms":460,"lbm_write_time_us":27260,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":352,"threads_started":5,"update_count":2000}
I20260812 06:17:21.567837   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=10.126437
I20260812 06:17:21.621018   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.053s	user 0.033s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19359,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:21.621580   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:21.633469   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4358,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.634308   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:21.790251   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.156s	user 0.135s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":11228,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25045,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.791056   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=11.118625
I20260812 06:17:21.832667   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.041s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17774,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:21.833448   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:21.849805   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4279,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:21.850296   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:22.001935   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.151s	user 0.094s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":629,"lbm_read_time_us":11323,"lbm_reads_lt_1ms":464,"lbm_write_time_us":31047,"lbm_writes_lt_1ms":443,"mutex_wait_us":391,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2000}
I20260812 06:17:22.002942   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=10.126437
I20260812 06:17:22.047103   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.044s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19041,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.047860   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:22.063066   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.015s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.063710   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:22.213019   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.146s	user 0.114s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":10479,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26742,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2000}
I20260812 06:17:22.213770   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=10.126437
I20260812 06:17:22.263964   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.050s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17488,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.264556   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:22.278273   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.278818   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:22.425400   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.146s	user 0.120s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":9898,"lbm_reads_lt_1ms":468,"lbm_write_time_us":29078,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:17:22.426103   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=10.126437
I20260812 06:17:22.483276   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.057s	user 0.034s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18166,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.483917   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:22.495908   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.496474   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:22.668154   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.171s	user 0.114s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":498,"lbm_read_time_us":12058,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26634,"lbm_writes_lt_1ms":443,"mutex_wait_us":88,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:22.668715   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=10.126437
I20260812 06:17:22.719584   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.051s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17212,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.720652   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:22.735615   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.736363   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushMRSOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:22.767787   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushMRSOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":294,"dirs.run_wall_time_us":1555,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1475,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:22.768428   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling LogGCOp(c1107709dfff456e94c5d7bcb10b175e): free 112692305 bytes of WAL
I20260812 06:17:22.768659   403 log_reader.cc:385] T c1107709dfff456e94c5d7bcb10b175e: removed 11 log segments from log reader
I20260812 06:17:22.768702   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000002 (ops 7-11)
I20260812 06:17:22.768733   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000003 (ops 12-16)
I20260812 06:17:22.768798   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000004 (ops 17-21)
I20260812 06:17:22.768831   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000005 (ops 22-26)
I20260812 06:17:22.768868   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000006 (ops 27-31)
I20260812 06:17:22.768909   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000007 (ops 32-36)
I20260812 06:17:22.768949   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000008 (ops 37-41)
I20260812 06:17:22.768988   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000009 (ops 42-46)
I20260812 06:17:22.769026   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000010 (ops 47-51)
I20260812 06:17:22.769065   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000011 (ops 52-56)
I20260812 06:17:22.769104   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000012 (ops 57-61)
I20260812 06:17:22.798080   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: LogGCOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:22.798664   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=3.181125
I20260812 06:17:22.811311   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4799,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:22.811779   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:22.834679   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.023s	user 0.007s	sys 0.013s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4831,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:22.835326   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:23.042001   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.206s	user 0.134s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":236,"lbm_read_time_us":15067,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33828,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20480,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:17:23.042945   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=14.095187
I20260812 06:17:23.111024   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.068s	user 0.022s	sys 0.043s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23475,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.111610   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling UndoDeltaBlockGCOp(c1107709dfff456e94c5d7bcb10b175e): 447 bytes on disk
I20260812 06:17:23.112106   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: UndoDeltaBlockGCOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:23.112628   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:23.144215   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.031s	user 0.006s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6078,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.144699   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:23.155857   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.156661   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:23.385365   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.228s	user 0.158s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836255,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":298,"lbm_read_time_us":15391,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38839,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:17:23.386332   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=14.095187
I20260812 06:17:23.461410   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.074s	user 0.041s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":30905,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.462155   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=3.181125
I20260812 06:17:23.487527   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.025s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4859,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:23.488082   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:23.498426   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3936,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:23.498924   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:23.732012   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.233s	user 0.154s	sys 0.071s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836245,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1332,"lbm_read_time_us":17528,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34582,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":3000}
I20260812 06:17:23.734793   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=16.079562
I20260812 06:17:23.800496   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.065s	user 0.053s	sys 0.011s Metrics: {"bytes_written":17599605,"delete_count":0,"lbm_write_time_us":26135,"lbm_writes_lt_1ms":432,"reinsert_count":0,"update_count":2145}
I20260812 06:17:23.801621   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.196750
I20260812 06:17:23.832630   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.031s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":3577,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:17:23.833359   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:23.852526   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.019s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5574,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.854923   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:24.106521   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.251s	user 0.178s	sys 0.071s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836229,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":936,"lbm_read_time_us":18378,"lbm_reads_lt_1ms":673,"lbm_write_time_us":41113,"lbm_writes_lt_1ms":643,"mutex_wait_us":441,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:24.107229   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=16.079562
I20260812 06:17:24.191177   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.084s	user 0.032s	sys 0.033s Metrics: {"bytes_written":17968824,"delete_count":0,"lbm_write_time_us":32040,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":439,"reinsert_count":0,"update_count":2190}
I20260812 06:17:24.191792   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=5.165500
I20260812 06:17:24.213249   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.021s	user 0.015s	sys 0.005s Metrics: {"bytes_written":6646165,"delete_count":0,"lbm_write_time_us":8597,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:17:24.214484   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:24.445429   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.231s	user 0.136s	sys 0.088s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836146,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":494,"lbm_read_time_us":15357,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38573,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":3000}
I20260812 06:17:24.446375   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=15.087375
I20260812 06:17:24.536295   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.090s	user 0.027s	sys 0.030s Metrics: {"bytes_written":17558582,"delete_count":0,"lbm_write_time_us":52575,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":430,"mutex_wait_us":657,"reinsert_count":0,"update_count":2140}
I20260812 06:17:24.537211   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=5.165500
I20260812 06:17:24.566701   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.029s	user 0.013s	sys 0.010s Metrics: {"bytes_written":7056408,"delete_count":0,"lbm_write_time_us":10155,"lbm_writes_lt_1ms":175,"reinsert_count":0,"update_count":860}
I20260812 06:17:24.567342   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushMRSOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:24.629076   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushMRSOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.061s	user 0.034s	sys 0.010s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1482,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2763,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:17:24.630209   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling LogGCOp(c1107709dfff456e94c5d7bcb10b175e): free 141338456 bytes of WAL
I20260812 06:17:24.630633   403 log_reader.cc:385] T c1107709dfff456e94c5d7bcb10b175e: removed 14 log segments from log reader
I20260812 06:17:24.630690   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000013 (ops 62-66)
I20260812 06:17:24.630730   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000014 (ops 67-70)
I20260812 06:17:24.630779   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000015 (ops 71-75)
I20260812 06:17:24.630978   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000016 (ops 76-80)
I20260812 06:17:24.631067   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000017 (ops 81-85)
I20260812 06:17:24.631089   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000018 (ops 86-90)
I20260812 06:17:24.631109   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000019 (ops 91-95)
I20260812 06:17:24.631137   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000020 (ops 96-100)
I20260812 06:17:24.631156   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000021 (ops 101-104)
I20260812 06:17:24.631175   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000022 (ops 105-109)
I20260812 06:17:24.631246   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000023 (ops 110-114)
I20260812 06:17:24.631294   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000024 (ops 115-119)
I20260812 06:17:24.631314   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000025 (ops 120-124)
I20260812 06:17:24.631385   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000026 (ops 125-129)
I20260812 06:17:24.665565   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: LogGCOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.035s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:17:24.666069   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=7.149875
I20260812 06:17:24.703657   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.037s	user 0.017s	sys 0.016s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":15025,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:24.704532   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:24.723862   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.019s	user 0.004s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7465,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:24.724429   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:25.027225   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.303s	user 0.209s	sys 0.093s Metrics: {"cfile_cache_miss":934,"cfile_cache_miss_bytes":41143613,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1215,"lbm_read_time_us":26946,"lbm_reads_lt_1ms":974,"lbm_write_time_us":51769,"lbm_writes_lt_1ms":943,"mutex_wait_us":105,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":527,"threads_started":6,"update_count":4500}
I20260812 06:17:25.028347   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling UndoDeltaBlockGCOp(c1107709dfff456e94c5d7bcb10b175e): 508 bytes on disk
I20260812 06:17:25.028977   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: UndoDeltaBlockGCOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:17:25.030042   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=22.032687
I20260812 06:17:25.120695   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.090s	user 0.061s	sys 0.028s Metrics: {"bytes_written":24614720,"delete_count":0,"lbm_write_time_us":40513,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:17:25.121222   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:25.142592   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.021s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.143239   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:25.158493   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.159143   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:25.405759   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.246s	user 0.178s	sys 0.067s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37041072,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":942,"lbm_read_time_us":18740,"lbm_reads_lt_1ms":873,"lbm_write_time_us":52406,"lbm_writes_lt_1ms":843,"mutex_wait_us":97,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":4000}
I20260812 06:17:25.406637   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=15.087375
I20260812 06:17:25.495657   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.089s	user 0.027s	sys 0.039s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":27241,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:17:25.496282   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=6.157687
I20260812 06:17:25.522817   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.026s	user 0.014s	sys 0.010s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10797,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:25.523387   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:25.706888   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.183s	user 0.139s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836136,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":533,"lbm_read_time_us":11174,"lbm_reads_lt_1ms":668,"lbm_write_time_us":36158,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":139136,"update_count":3000}
I20260812 06:17:25.707677   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=14.095187
I20260812 06:17:25.757648   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.050s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22437,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.758405   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:25.774837   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5933,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.775624   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:25.976294   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.200s	user 0.134s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":12553,"lbm_reads_lt_1ms":564,"lbm_write_time_us":37558,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29312,"update_count":2500}
I20260812 06:17:25.977077   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=14.095187
I20260812 06:17:26.033116   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.056s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23704,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.033926   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:26.218343   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.184s	user 0.102s	sys 0.080s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":298,"lbm_read_time_us":13331,"lbm_reads_lt_1ms":463,"lbm_write_time_us":30575,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:17:26.219264   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=14.095187
I20260812 06:17:26.270848   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.051s	user 0.036s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22823,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.271482   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:26.288739   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6659,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.289669   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushMRSOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:26.328886   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushMRSOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.039s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":407,"dirs.run_wall_time_us":2434,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1670,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:26.329799   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling LogGCOp(c1107709dfff456e94c5d7bcb10b175e): free 128867720 bytes of WAL
I20260812 06:17:26.330084   403 log_reader.cc:385] T c1107709dfff456e94c5d7bcb10b175e: removed 13 log segments from log reader
I20260812 06:17:26.330147   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000027 (ops 130-134)
I20260812 06:17:26.330185   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000028 (ops 135-139)
I20260812 06:17:26.330209   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000029 (ops 140-144)
I20260812 06:17:26.330231   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000030 (ops 145-148)
I20260812 06:17:26.330258   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000031 (ops 149-153)
I20260812 06:17:26.330288   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000032 (ops 154-158)
I20260812 06:17:26.330319   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000033 (ops 159-162)
I20260812 06:17:26.330343   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000034 (ops 163-167)
I20260812 06:17:26.330370   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000035 (ops 168-172)
I20260812 06:17:26.330394   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000036 (ops 173-177)
I20260812 06:17:26.330430   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000037 (ops 178-182)
I20260812 06:17:26.330456   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000038 (ops 183-186)
I20260812 06:17:26.330477   403 log.cc:1079] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: Deleting log segment in path: /tmp/dist-test-taskStPjNX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515434756485-32395-0/minicluster-data/ts-0-root/wals/c1107709dfff456e94c5d7bcb10b175e/wal-000000039 (ops 187-191)
I20260812 06:17:26.367826   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: LogGCOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.038s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:17:26.368304   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling UndoDeltaBlockGCOp(c1107709dfff456e94c5d7bcb10b175e): 472 bytes on disk
I20260812 06:17:26.368779   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: UndoDeltaBlockGCOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.369313   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:26.399040   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.030s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.399597   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=2.188937
I20260812 06:17:26.411458   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.012s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.412115   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:26.616983 32395 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.502s	user 2.062s	sys 0.161s
I20260812 06:17:26.666851   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.255s	user 0.165s	sys 0.086s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938785,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17445,"lbm_reads_lt_1ms":770,"lbm_write_time_us":44843,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:17:26.667441   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e): perf score=14.095187
I20260812 06:17:26.703020   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: FlushDeltaMemStoresOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.035s	user 0.011s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17055,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.703580   502 maintenance_manager.cc:419] P 6c4e947993b54095b4f269847bc33d70: Scheduling MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e): perf score=1.000000
I20260812 06:17:26.728703 32395 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.111s	user 0.002s	sys 0.000s
I20260812 06:17:26.729314 32395 tablet_server.cc:179] TabletServer@127.31.162.193:0 shutting down...
I20260812 06:17:26.845906   403 maintenance_manager.cc:643] P 6c4e947993b54095b4f269847bc33d70: MajorDeltaCompactionOp(c1107709dfff456e94c5d7bcb10b175e) complete. Timing: real 0.142s	user 0.103s	sys 0.038s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631191,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":991,"lbm_read_time_us":12783,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25310,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.846983 32395 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:26.847255 32395 tablet_replica.cc:333] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70: stopping tablet replica
I20260812 06:17:26.847411 32395 raft_consensus.cc:2243] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:26.847599 32395 raft_consensus.cc:2272] T c1107709dfff456e94c5d7bcb10b175e P 6c4e947993b54095b4f269847bc33d70 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:26.853049 32395 tablet_server.cc:196] TabletServer@127.31.162.193:0 shutdown complete.
I20260812 06:17:26.892980 32395 master.cc:562] Master@127.31.162.254:33577 shutting down...
I20260812 06:17:26.898448 32395 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:26.898691 32395 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:26.898743 32395 tablet_replica.cc:333] T 00000000000000000000000000000000 P 40769b04dcd04ee7a5dd8bd1948d9d36: stopping tablet replica
I20260812 06:17:26.913293 32395 master.cc:584] Master@127.31.162.254:33577 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6179 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12251 ms total)

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