[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:31.371203 19921 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.116.126:43339
I20260812 06:19:31.372308 19921 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:31.372946 19921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:31.379522 19928 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:31.379518 19930 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.379593 19921 server_base.cc:1061] running on GCE node
W20260812 06:19:31.379844 19932 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.380370 19921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:31.380477 19921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:31.380507 19921 hybrid_clock.cc:648] HybridClock initialized: now 1786515571380506 us; error 0 us; skew 500 ppm
I20260812 06:19:31.382449 19921 webserver.cc:533] Webserver started at http://127.19.116.126:43871/ using document root <none> and password file <none>
I20260812 06:19:31.383009 19921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:31.383068 19921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:31.383275 19921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:31.384985 19921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/master-0-root/instance:
uuid: "7762e38d8df343bfa4b0bf63cb16ecf0"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-rmhg"
I20260812 06:19:31.388785 19921 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:19:31.391095 19940 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.392305 19921 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:31.392479 19921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/master-0-root
uuid: "7762e38d8df343bfa4b0bf63cb16ecf0"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-rmhg"
I20260812 06:19:31.392591 19921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:31.416512 19921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:31.417286 19921 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:31.417477 19921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:31.425012 19921 rpc_server.cc:307] RPC server started. Bound to: 127.19.116.126:43339
I20260812 06:19:31.425036 20024 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.116.126:43339 every 8 connection(s)
I20260812 06:19:31.427424 20025 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:31.433207 20025 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0: Bootstrap starting.
I20260812 06:19:31.435674 20025 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:31.436734 20025 log.cc:826] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:31.438758 20025 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0: No bootstrap required, opened a new log
I20260812 06:19:31.441793 20025 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7762e38d8df343bfa4b0bf63cb16ecf0" member_type: VOTER }
I20260812 06:19:31.441980 20025 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:31.442049 20025 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7762e38d8df343bfa4b0bf63cb16ecf0, State: Initialized, Role: FOLLOWER
I20260812 06:19:31.442627 20025 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [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: "7762e38d8df343bfa4b0bf63cb16ecf0" member_type: VOTER }
I20260812 06:19:31.442762 20025 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:31.442809 20025 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:31.442896 20025 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:31.443709 20025 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7762e38d8df343bfa4b0bf63cb16ecf0" member_type: VOTER }
I20260812 06:19:31.444146 20025 leader_election.cc:304] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [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: 7762e38d8df343bfa4b0bf63cb16ecf0; no voters: 
I20260812 06:19:31.444476 20025 leader_election.cc:290] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:31.444589 20030 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:31.444813 20030 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 1 LEADER]: Becoming Leader. State: Replica: 7762e38d8df343bfa4b0bf63cb16ecf0, State: Running, Role: LEADER
I20260812 06:19:31.445241 20030 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [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: "7762e38d8df343bfa4b0bf63cb16ecf0" member_type: VOTER }
I20260812 06:19:31.445540 20025 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:31.447139 20035 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7762e38d8df343bfa4b0bf63cb16ecf0. Latest consensus state: current_term: 1 leader_uuid: "7762e38d8df343bfa4b0bf63cb16ecf0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7762e38d8df343bfa4b0bf63cb16ecf0" member_type: VOTER } }
I20260812 06:19:31.447175 20031 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7762e38d8df343bfa4b0bf63cb16ecf0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7762e38d8df343bfa4b0bf63cb16ecf0" member_type: VOTER } }
I20260812 06:19:31.447285 20035 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:31.447293 20031 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:31.447671 20054 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:31.447887 19921 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:31.450369 20054 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:31.455804 20054 catalog_manager.cc:1383] Generated new cluster ID: eccf28c9d32945d2a91ceb4d6903870f
I20260812 06:19:31.455904 20054 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:31.468375 20054 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:31.469523 20054 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:31.480285 20054 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0: Generated new TSK 0
I20260812 06:19:31.481050 20054 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:31.512989 19921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:31.516180 20072 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:31.516171 20070 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.516321 19921 server_base.cc:1061] running on GCE node
W20260812 06:19:31.516171 20077 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.516705 19921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:31.516770 19921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:31.516794 19921 hybrid_clock.cc:648] HybridClock initialized: now 1786515571516793 us; error 0 us; skew 500 ppm
I20260812 06:19:31.517797 19921 webserver.cc:533] Webserver started at http://127.19.116.65:36105/ using document root <none> and password file <none>
I20260812 06:19:31.517973 19921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:31.518042 19921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:31.518122 19921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:31.518584 19921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/instance:
uuid: "84b6e06dc4b248368759012c7f69d515"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-rmhg"
I20260812 06:19:31.520454 19921 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:31.521574 20085 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.521857 19921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:31.521937 19921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root
uuid: "84b6e06dc4b248368759012c7f69d515"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-rmhg"
I20260812 06:19:31.522061 19921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:31.534407 19921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:31.534947 19921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:31.535537 19921 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:31.536588 19921 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:31.536660 19921 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.536727 19921 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:31.536757 19921 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.543589 19921 rpc_server.cc:307] RPC server started. Bound to: 127.19.116.65:43641
I20260812 06:19:31.543630 20193 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.116.65:43641 every 8 connection(s)
I20260812 06:19:31.554363 20196 heartbeater.cc:344] Connected to a master server at 127.19.116.126:43339
I20260812 06:19:31.554649 20196 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:31.555158 20196 heartbeater.cc:507] Master 127.19.116.126:43339 requested a full tablet report, sending...
I20260812 06:19:31.556675 19966 ts_manager.cc:194] Registered new tserver with Master: 84b6e06dc4b248368759012c7f69d515 (127.19.116.65:43641)
I20260812 06:19:31.556813 19921 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012524604s
I20260812 06:19:31.557935 19966 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57600
I20260812 06:19:31.566757 19966 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57614:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:31.581658 20132 tablet_service.cc:1511] Processing CreateTablet for tablet 7dca7520a0b04d5fae9a2e357a03df34 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9db925f1dc2d485a872d0dd38f65d4e7]), partition=
I20260812 06:19:31.582198 20132 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7dca7520a0b04d5fae9a2e357a03df34. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:31.585227 20213 tablet_bootstrap.cc:492] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Bootstrap starting.
I20260812 06:19:31.586570 20213 tablet_bootstrap.cc:654] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:31.587903 20213 tablet_bootstrap.cc:492] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: No bootstrap required, opened a new log
I20260812 06:19:31.588038 20213 ts_tablet_manager.cc:1403] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:31.588645 20213 raft_consensus.cc:359] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84b6e06dc4b248368759012c7f69d515" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43641 } }
I20260812 06:19:31.588788 20213 raft_consensus.cc:385] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:31.588827 20213 raft_consensus.cc:740] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 84b6e06dc4b248368759012c7f69d515, State: Initialized, Role: FOLLOWER
I20260812 06:19:31.589017 20213 consensus_queue.cc:260] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [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: "84b6e06dc4b248368759012c7f69d515" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43641 } }
I20260812 06:19:31.589131 20213 raft_consensus.cc:399] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:31.589207 20213 raft_consensus.cc:493] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:31.589260 20213 raft_consensus.cc:3060] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:31.590046 20213 raft_consensus.cc:515] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84b6e06dc4b248368759012c7f69d515" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43641 } }
I20260812 06:19:31.590193 20213 leader_election.cc:304] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [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: 84b6e06dc4b248368759012c7f69d515; no voters: 
I20260812 06:19:31.590420 20213 leader_election.cc:290] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:31.590545 20216 raft_consensus.cc:2804] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:31.590713 20216 raft_consensus.cc:697] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 1 LEADER]: Becoming Leader. State: Replica: 84b6e06dc4b248368759012c7f69d515, State: Running, Role: LEADER
I20260812 06:19:31.590816 20213 ts_tablet_manager.cc:1434] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:31.590919 20216 consensus_queue.cc:237] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [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: "84b6e06dc4b248368759012c7f69d515" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43641 } }
I20260812 06:19:31.591096 20196 heartbeater.cc:499] Master 127.19.116.126:43339 was elected leader, sending a full tablet report...
I20260812 06:19:31.594120 19966 catalog_manager.cc:5719] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 reported cstate change: term changed from 0 to 1, leader changed from <none> to 84b6e06dc4b248368759012c7f69d515 (127.19.116.65). New cstate: current_term: 1 leader_uuid: "84b6e06dc4b248368759012c7f69d515" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84b6e06dc4b248368759012c7f69d515" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43641 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:31.656785 19921 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.016s	sys 0.011s
I20260812 06:19:31.794893 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushMRSOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=19.054940
I20260812 06:19:31.971228 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushMRSOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.176s	user 0.145s	sys 0.024s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":254,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":720,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42218,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":148,"threads_started":1,"update_count":1500}
I20260812 06:19:31.972543 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling LogGCOp(7dca7520a0b04d5fae9a2e357a03df34): free 20743880 bytes of WAL
I20260812 06:19:31.972952 20091 log_reader.cc:385] T 7dca7520a0b04d5fae9a2e357a03df34: removed 2 log segments from log reader
I20260812 06:19:31.973043 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000001 (ops 1-6)
I20260812 06:19:31.973199 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000002 (ops 7-11)
I20260812 06:19:31.978256 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: LogGCOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:31.978878 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling UndoDeltaBlockGCOp(7dca7520a0b04d5fae9a2e357a03df34): 16411393 bytes on disk
I20260812 06:19:31.979679 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: UndoDeltaBlockGCOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.980263 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:31.995316 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.996240 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:32.138247 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.142s	user 0.102s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":576,"lbm_read_time_us":8922,"lbm_reads_lt_1ms":460,"lbm_write_time_us":22353,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":312,"threads_started":5,"update_count":2000}
I20260812 06:19:32.138864 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=11.118625
I20260812 06:19:32.172420 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.033s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14036,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:32.172941 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:32.192561 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4721,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:32.193064 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:32.312196 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.119s	user 0.094s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":7341,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22459,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:19:32.312742 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:32.348912 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.036s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14507,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.349618 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:32.365863 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6147,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.366397 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:32.492421 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.126s	user 0.099s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":562,"lbm_read_time_us":9993,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22761,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":51200,"update_count":2000}
I20260812 06:19:32.493026 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:32.541738 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.048s	user 0.027s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18078,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.542389 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:32.559346 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.017s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.559878 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:32.698891 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.139s	user 0.090s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":11043,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22034,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":47360,"update_count":2000}
I20260812 06:19:32.699501 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:32.742843 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.043s	user 0.033s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16454,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.743341 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:32.754385 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.755126 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:32.874361 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.119s	user 0.099s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":8299,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23474,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:19:32.874876 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:32.914434 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.039s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14334,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.915030 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:32.925885 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3837,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.926625 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:33.043753 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.117s	user 0.077s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":613,"lbm_read_time_us":8865,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23226,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:33.044250 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:33.093791 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.049s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14759,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.094485 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:33.110031 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5865,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.110584 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushMRSOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:33.150766 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushMRSOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.040s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1381,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1477,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:33.151763 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling LogGCOp(7dca7520a0b04d5fae9a2e357a03df34): free 112239259 bytes of WAL
I20260812 06:19:33.152009 20091 log_reader.cc:385] T 7dca7520a0b04d5fae9a2e357a03df34: removed 11 log segments from log reader
I20260812 06:19:33.152057 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000003 (ops 12-16)
I20260812 06:19:33.152099 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000004 (ops 17-20)
I20260812 06:19:33.152168 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000005 (ops 21-25)
I20260812 06:19:33.152194 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000006 (ops 26-30)
I20260812 06:19:33.152226 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000007 (ops 31-35)
I20260812 06:19:33.152258 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000008 (ops 36-40)
I20260812 06:19:33.152288 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000009 (ops 41-45)
I20260812 06:19:33.152320 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000010 (ops 46-50)
I20260812 06:19:33.152350 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000011 (ops 51-55)
I20260812 06:19:33.152380 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000012 (ops 56-60)
I20260812 06:19:33.152412 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000013 (ops 61-65)
I20260812 06:19:33.172046 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: LogGCOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:33.172403 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=3.181125
I20260812 06:19:33.195796 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.023s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:33.196311 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:33.205765 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3299,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:33.206282 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:33.416525 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.210s	user 0.110s	sys 0.096s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":286,"lbm_read_time_us":15091,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32226,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":69888,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:33.417264 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling UndoDeltaBlockGCOp(7dca7520a0b04d5fae9a2e357a03df34): 447 bytes on disk
I20260812 06:19:33.417922 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: UndoDeltaBlockGCOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:33.418591 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=14.095187
I20260812 06:19:33.470182 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.051s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23154,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.470744 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:33.611140 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.140s	user 0.103s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672161,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":805,"lbm_read_time_us":11319,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22482,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:19:33.611784 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:33.651737 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.040s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17995,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.652179 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:33.662990 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.663509 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:33.792892 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.129s	user 0.096s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":245,"lbm_read_time_us":10340,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22352,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.793507 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:33.834677 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.041s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17987,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.835297 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:33.846050 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3997,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.846655 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:33.973799 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.127s	user 0.101s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":10398,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21804,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":43904,"update_count":2000}
I20260812 06:19:33.974465 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:34.011682 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.037s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15795,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.012214 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:34.024516 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.025756 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:34.145920 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.120s	user 0.095s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":640,"lbm_read_time_us":10075,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22003,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29952,"update_count":2000}
I20260812 06:19:34.146636 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:34.196412 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.050s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16820,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.197055 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:34.207621 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3817,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.208148 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:34.352331 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.144s	user 0.096s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":105,"lbm_read_time_us":11647,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22175,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:19:34.353555 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:34.393784 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.040s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16852,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.394400 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:34.407347 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.407819 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:34.529758 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.122s	user 0.094s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":153,"lbm_read_time_us":9849,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23103,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:19:34.530304 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=10.126437
I20260812 06:19:34.567196 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.037s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14305,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.567731 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:34.578511 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3843,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.579084 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushMRSOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:34.612135 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushMRSOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.033s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1520,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1851,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:34.612864 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling LogGCOp(7dca7520a0b04d5fae9a2e357a03df34): free 128867497 bytes of WAL
I20260812 06:19:34.613098 20091 log_reader.cc:385] T 7dca7520a0b04d5fae9a2e357a03df34: removed 13 log segments from log reader
I20260812 06:19:34.613180 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000014 (ops 66-70)
I20260812 06:19:34.613232 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000015 (ops 71-74)
I20260812 06:19:34.613268 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000016 (ops 75-79)
I20260812 06:19:34.613287 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000017 (ops 80-84)
I20260812 06:19:34.613318 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000018 (ops 85-88)
I20260812 06:19:34.613349 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000019 (ops 89-93)
I20260812 06:19:34.613380 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000020 (ops 94-98)
I20260812 06:19:34.613413 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000021 (ops 99-103)
I20260812 06:19:34.613445 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000022 (ops 104-108)
I20260812 06:19:34.613476 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000023 (ops 109-113)
I20260812 06:19:34.613509 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000024 (ops 114-118)
I20260812 06:19:34.613538 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000025 (ops 119-122)
I20260812 06:19:34.613569 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000026 (ops 123-127)
I20260812 06:19:34.636370 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: LogGCOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.023s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:19:34.636780 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling UndoDeltaBlockGCOp(7dca7520a0b04d5fae9a2e357a03df34): 473 bytes on disk
I20260812 06:19:34.637243 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: UndoDeltaBlockGCOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.637744 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=3.181125
I20260812 06:19:34.650583 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4635978,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:34.651098 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:34.665863 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":5465,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:19:34.666536 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:34.839818 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.173s	user 0.130s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":675,"lbm_read_time_us":11120,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33142,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":134400,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:19:34.840801 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=14.095187
I20260812 06:19:34.913403 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.072s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":42636,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.913913 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=3.181125
I20260812 06:19:34.925704 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:34.926249 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:34.940501 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4797,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.941262 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:35.117201 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.176s	user 0.147s	sys 0.024s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":622,"lbm_read_time_us":13366,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34722,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":75776,"update_count":3000}
I20260812 06:19:35.117926 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=14.095187
I20260812 06:19:35.159053 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.041s	user 0.026s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16733,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.159675 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:35.175729 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.176353 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:35.326494 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.150s	user 0.088s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":9480,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26087,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:19:35.327280 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=14.095187
I20260812 06:19:35.374701 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.047s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18419,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.375329 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:35.514806 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.139s	user 0.097s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":937,"lbm_read_time_us":9236,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21870,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:19:35.515372 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=14.095187
I20260812 06:19:35.573637 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.058s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22679,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.574184 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:35.585484 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3773,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.585989 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:35.749423 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.163s	user 0.115s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":10830,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26234,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:35.750066 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=11.118625
I20260812 06:19:35.787057 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.037s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15020,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:35.787741 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:35.804409 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5215,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.805068 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:35.932839 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.128s	user 0.096s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1934,"lbm_read_time_us":8230,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22645,"lbm_writes_lt_1ms":443,"mutex_wait_us":570,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.933499 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=11.118625
I20260812 06:19:35.970036 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.036s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15496,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:35.970618 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:35.995144 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.024s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4159,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.995649 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:36.005811 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.006326 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushMRSOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:36.034940 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushMRSOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1226,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1559,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:36.035754 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling LogGCOp(7dca7520a0b04d5fae9a2e357a03df34): free 120553589 bytes of WAL
I20260812 06:19:36.036001 20091 log_reader.cc:385] T 7dca7520a0b04d5fae9a2e357a03df34: removed 12 log segments from log reader
I20260812 06:19:36.036063 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000027 (ops 128-132)
I20260812 06:19:36.036108 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000028 (ops 133-137)
I20260812 06:19:36.036144 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000029 (ops 138-142)
I20260812 06:19:36.036176 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000030 (ops 143-146)
I20260812 06:19:36.036204 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000031 (ops 147-151)
I20260812 06:19:36.036231 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000032 (ops 152-156)
I20260812 06:19:36.036258 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000033 (ops 157-161)
I20260812 06:19:36.036289 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000034 (ops 162-166)
I20260812 06:19:36.036320 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000035 (ops 167-170)
I20260812 06:19:36.036347 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000036 (ops 171-175)
I20260812 06:19:36.036374 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000037 (ops 176-180)
I20260812 06:19:36.036402 20091 log.cc:1079] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/7dca7520a0b04d5fae9a2e357a03df34/wal-000000038 (ops 181-185)
I20260812 06:19:36.060158 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: LogGCOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:36.060591 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling UndoDeltaBlockGCOp(7dca7520a0b04d5fae9a2e357a03df34): 481 bytes on disk
I20260812 06:19:36.061033 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: UndoDeltaBlockGCOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:36.061595 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=3.181125
I20260812 06:19:36.076869 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.015s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4221,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:36.077407 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:36.091686 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5003,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.092360 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:36.274083 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.181s	user 0.149s	sys 0.032s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979848,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":567,"lbm_read_time_us":13627,"lbm_reads_lt_1ms":775,"lbm_write_time_us":35730,"lbm_writes_lt_1ms":743,"mutex_wait_us":267,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6912,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:19:36.275014 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=14.095187
I20260812 06:19:36.318955 19921 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.662s	user 1.738s	sys 0.115s
I20260812 06:19:36.322279 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.047s	user 0.022s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18549,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.322890 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=2.188937
I20260812 06:19:36.334148 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: FlushDeltaMemStoresOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4665,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":500}
I20260812 06:19:36.334619 20198 maintenance_manager.cc:419] P 84b6e06dc4b248368759012c7f69d515: Scheduling MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34): perf score=1.000000
I20260812 06:19:36.366859 19921 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.047s	user 0.002s	sys 0.000s
I20260812 06:19:36.367540 19921 tablet_server.cc:179] TabletServer@127.19.116.65:0 shutting down...
I20260812 06:19:36.444928 20091 maintenance_manager.cc:643] P 84b6e06dc4b248368759012c7f69d515: MajorDeltaCompactionOp(7dca7520a0b04d5fae9a2e357a03df34) complete. Timing: real 0.110s	user 0.089s	sys 0.020s Metrics: {"cfile_cache_hit":367,"cfile_cache_hit_bytes":15015394,"cfile_cache_miss":165,"cfile_cache_miss_bytes":9759295,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":266,"lbm_read_time_us":4060,"lbm_reads_lt_1ms":197,"lbm_write_time_us":23161,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":42240,"update_count":2500}
I20260812 06:19:36.445990 19921 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:36.446362 19921 tablet_replica.cc:333] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515: stopping tablet replica
I20260812 06:19:36.446580 19921 raft_consensus.cc:2243] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:36.446858 19921 raft_consensus.cc:2272] T 7dca7520a0b04d5fae9a2e357a03df34 P 84b6e06dc4b248368759012c7f69d515 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:36.462013 19921 tablet_server.cc:196] TabletServer@127.19.116.65:0 shutdown complete.
I20260812 06:19:36.490315 19921 master.cc:562] Master@127.19.116.126:43339 shutting down...
I20260812 06:19:36.493650 19921 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:36.493837 19921 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:36.493893 19921 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7762e38d8df343bfa4b0bf63cb16ecf0: stopping tablet replica
I20260812 06:19:36.506184 19921 master.cc:584] Master@127.19.116.126:43339 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5214 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:36.585371 19921 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.116.126:35705
I20260812 06:19:36.585759 19921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.587759 20241 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.587770 20245 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.587954 19921 server_base.cc:1061] running on GCE node
W20260812 06:19:36.587882 20242 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.588169 19921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.588214 19921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:36.588228 19921 hybrid_clock.cc:648] HybridClock initialized: now 1786515576588228 us; error 0 us; skew 500 ppm
I20260812 06:19:36.589038 19921 webserver.cc:533] Webserver started at http://127.19.116.126:41761/ using document root <none> and password file <none>
I20260812 06:19:36.589248 19921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.589298 19921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.589358 19921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.589697 19921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/master-0-root/instance:
uuid: "293a23cd26474205b3c752bb8b93abfd"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-rmhg"
I20260812 06:19:36.591130 19921 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:36.592173 20255 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.592401 19921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:36.592473 19921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/master-0-root
uuid: "293a23cd26474205b3c752bb8b93abfd"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-rmhg"
I20260812 06:19:36.592546 19921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:36.601462 19921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.601881 19921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.605894 19921 rpc_server.cc:307] RPC server started. Bound to: 127.19.116.126:35705
I20260812 06:19:36.614224 20342 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.116.126:35705 every 8 connection(s)
I20260812 06:19:36.618777 20343 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:36.620636 20343 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd: Bootstrap starting.
I20260812 06:19:36.621495 20343 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.622696 20343 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd: No bootstrap required, opened a new log
I20260812 06:19:36.623111 20343 raft_consensus.cc:359] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "293a23cd26474205b3c752bb8b93abfd" member_type: VOTER }
I20260812 06:19:36.623205 20343 raft_consensus.cc:385] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.623226 20343 raft_consensus.cc:740] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 293a23cd26474205b3c752bb8b93abfd, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.623334 20343 consensus_queue.cc:260] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [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: "293a23cd26474205b3c752bb8b93abfd" member_type: VOTER }
I20260812 06:19:36.623389 20343 raft_consensus.cc:399] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.623416 20343 raft_consensus.cc:493] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.623449 20343 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.624138 20343 raft_consensus.cc:515] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "293a23cd26474205b3c752bb8b93abfd" member_type: VOTER }
I20260812 06:19:36.624266 20343 leader_election.cc:304] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [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: 293a23cd26474205b3c752bb8b93abfd; no voters: 
I20260812 06:19:36.624467 20343 leader_election.cc:290] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.624657 20346 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.624857 20346 raft_consensus.cc:697] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 1 LEADER]: Becoming Leader. State: Replica: 293a23cd26474205b3c752bb8b93abfd, State: Running, Role: LEADER
I20260812 06:19:36.624909 20343 sys_catalog.cc:565] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:36.625010 20346 consensus_queue.cc:237] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [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: "293a23cd26474205b3c752bb8b93abfd" member_type: VOTER }
I20260812 06:19:36.625500 20350 sys_catalog.cc:455] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "293a23cd26474205b3c752bb8b93abfd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "293a23cd26474205b3c752bb8b93abfd" member_type: VOTER } }
I20260812 06:19:36.625547 20351 sys_catalog.cc:455] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [sys.catalog]: SysCatalogTable state changed. Reason: New leader 293a23cd26474205b3c752bb8b93abfd. Latest consensus state: current_term: 1 leader_uuid: "293a23cd26474205b3c752bb8b93abfd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "293a23cd26474205b3c752bb8b93abfd" member_type: VOTER } }
I20260812 06:19:36.625608 20350 sys_catalog.cc:458] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.625634 20351 sys_catalog.cc:458] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.625857 20357 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:36.626756 20357 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:36.627049 19921 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:36.628798 20357 catalog_manager.cc:1383] Generated new cluster ID: d0b161617de04f22a9b6f88bde2214eb
I20260812 06:19:36.628857 20357 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:36.637935 20357 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:36.638543 20357 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:36.646523 20357 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd: Generated new TSK 0
I20260812 06:19:36.646731 20357 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:36.659824 19921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.662070 20372 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.662178 19921 server_base.cc:1061] running on GCE node
W20260812 06:19:36.662191 20376 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.662343 20373 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:36.662576 19921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.662636 19921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:36.662657 19921 hybrid_clock.cc:648] HybridClock initialized: now 1786515576662657 us; error 0 us; skew 500 ppm
I20260812 06:19:36.663569 19921 webserver.cc:533] Webserver started at http://127.19.116.65:40003/ using document root <none> and password file <none>
I20260812 06:19:36.663750 19921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.663806 19921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.663888 19921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.664284 19921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/instance:
uuid: "e9466907e2c341a8975e7da60c2ff657"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-rmhg"
I20260812 06:19:36.665942 19921 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:36.666941 20385 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.667192 19921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:36.667265 19921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root
uuid: "e9466907e2c341a8975e7da60c2ff657"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-rmhg"
I20260812 06:19:36.667344 19921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:36.680058 19921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.680488 19921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.680832 19921 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:36.681363 19921 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:36.681404 19921 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.681452 19921 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:36.681480 19921 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.685787 19921 rpc_server.cc:307] RPC server started. Bound to: 127.19.116.65:43293
I20260812 06:19:36.685808 20491 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.116.65:43293 every 8 connection(s)
I20260812 06:19:36.700161 20492 heartbeater.cc:344] Connected to a master server at 127.19.116.126:35705
I20260812 06:19:36.700304 20492 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:36.700574 20492 heartbeater.cc:507] Master 127.19.116.126:35705 requested a full tablet report, sending...
I20260812 06:19:36.701314 20282 ts_manager.cc:194] Registered new tserver with Master: e9466907e2c341a8975e7da60c2ff657 (127.19.116.65:43293)
I20260812 06:19:36.701606 19921 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015435367s
I20260812 06:19:36.702344 20282 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51394
I20260812 06:19:36.709481 20282 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51402:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:36.719203 20429 tablet_service.cc:1511] Processing CreateTablet for tablet 63137000980a444abd3565e5a1d89812 (DEFAULT_TABLE table=heavy-update-compaction-test [id=79221adde61c4841bcfafd4fe178905f]), partition=
I20260812 06:19:36.719514 20429 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 63137000980a444abd3565e5a1d89812. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:36.721796 20508 tablet_bootstrap.cc:492] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Bootstrap starting.
I20260812 06:19:36.722689 20508 tablet_bootstrap.cc:654] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.723857 20508 tablet_bootstrap.cc:492] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: No bootstrap required, opened a new log
I20260812 06:19:36.723948 20508 ts_tablet_manager.cc:1403] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:36.724485 20508 raft_consensus.cc:359] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9466907e2c341a8975e7da60c2ff657" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43293 } }
I20260812 06:19:36.724583 20508 raft_consensus.cc:385] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.724604 20508 raft_consensus.cc:740] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e9466907e2c341a8975e7da60c2ff657, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.724752 20508 consensus_queue.cc:260] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [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: "e9466907e2c341a8975e7da60c2ff657" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43293 } }
I20260812 06:19:36.724864 20508 raft_consensus.cc:399] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.724911 20508 raft_consensus.cc:493] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.724954 20508 raft_consensus.cc:3060] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.725783 20508 raft_consensus.cc:515] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9466907e2c341a8975e7da60c2ff657" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43293 } }
I20260812 06:19:36.725924 20508 leader_election.cc:304] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [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: e9466907e2c341a8975e7da60c2ff657; no voters: 
I20260812 06:19:36.726128 20508 leader_election.cc:290] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.726246 20514 raft_consensus.cc:2804] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.726481 20492 heartbeater.cc:499] Master 127.19.116.126:35705 was elected leader, sending a full tablet report...
I20260812 06:19:36.726485 20514 raft_consensus.cc:697] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 1 LEADER]: Becoming Leader. State: Replica: e9466907e2c341a8975e7da60c2ff657, State: Running, Role: LEADER
I20260812 06:19:36.726487 20508 ts_tablet_manager.cc:1434] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:36.726697 20514 consensus_queue.cc:237] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [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: "e9466907e2c341a8975e7da60c2ff657" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43293 } }
I20260812 06:19:36.728176 20282 catalog_manager.cc:5719] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 reported cstate change: term changed from 0 to 1, leader changed from <none> to e9466907e2c341a8975e7da60c2ff657 (127.19.116.65). New cstate: current_term: 1 leader_uuid: "e9466907e2c341a8975e7da60c2ff657" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9466907e2c341a8975e7da60c2ff657" member_type: VOTER last_known_addr { host: "127.19.116.65" port: 43293 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:36.788398 19921 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.014s	sys 0.008s
I20260812 06:19:36.936789 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushMRSOp(63137000980a444abd3565e5a1d89812): perf score=19.054940
I20260812 06:19:37.087276 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushMRSOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.150s	user 0.126s	sys 0.016s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":920,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34620,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":4864,"update_count":1500}
I20260812 06:19:37.087962 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling LogGCOp(63137000980a444abd3565e5a1d89812): free 20743880 bytes of WAL
I20260812 06:19:37.088208 20391 log_reader.cc:385] T 63137000980a444abd3565e5a1d89812: removed 2 log segments from log reader
I20260812 06:19:37.088258 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000001 (ops 1-6)
I20260812 06:19:37.088289 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000002 (ops 7-11)
I20260812 06:19:37.091835 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: LogGCOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:37.092294 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling UndoDeltaBlockGCOp(63137000980a444abd3565e5a1d89812): 16411394 bytes on disk
I20260812 06:19:37.092770 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: UndoDeltaBlockGCOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:37.093271 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:37.109586 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.110040 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:37.254215 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.144s	user 0.094s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":639,"lbm_read_time_us":9317,"lbm_reads_lt_1ms":460,"lbm_write_time_us":21961,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":330,"threads_started":5,"update_count":2000}
I20260812 06:19:37.254797 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:37.297363 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.042s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18944,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.297958 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:37.432912 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.135s	user 0.080s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":777,"lbm_read_time_us":9589,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21526,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:19:37.433497 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=10.126437
I20260812 06:19:37.466629 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.033s	user 0.028s	sys 0.003s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13738,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.467231 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:37.482890 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6340,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.483321 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:37.606902 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.123s	user 0.087s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":265,"lbm_read_time_us":9552,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23177,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:19:37.607482 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=10.126437
I20260812 06:19:37.651973 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.044s	user 0.020s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12605,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.652639 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:37.664831 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4064,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.665431 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:37.784940 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.119s	user 0.086s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1089,"lbm_read_time_us":8658,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22118,"lbm_writes_lt_1ms":443,"mutex_wait_us":268,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.785511 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=10.126437
I20260812 06:19:37.831209 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.046s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15683,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.831909 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:37.848119 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.848847 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:37.976450 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.127s	user 0.095s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":255,"lbm_read_time_us":10647,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23173,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:19:37.977097 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=10.126437
I20260812 06:19:38.022092 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.045s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14144,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.022756 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:38.033546 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.034011 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:38.177968 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.144s	user 0.080s	sys 0.063s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1168,"lbm_read_time_us":10267,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23357,"lbm_writes_lt_1ms":443,"mutex_wait_us":457,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:19:38.178722 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=10.126437
I20260812 06:19:38.211593 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.033s	user 0.021s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13574,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.212262 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:38.228757 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.229360 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushMRSOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:38.261008 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushMRSOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1214,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1380,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:38.261646 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling LogGCOp(63137000980a444abd3565e5a1d89812): free 112692365 bytes of WAL
I20260812 06:19:38.261884 20391 log_reader.cc:385] T 63137000980a444abd3565e5a1d89812: removed 11 log segments from log reader
I20260812 06:19:38.261930 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000003 (ops 12-16)
I20260812 06:19:38.261958 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000004 (ops 17-21)
I20260812 06:19:38.261976 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000005 (ops 22-26)
I20260812 06:19:38.262003 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000006 (ops 27-31)
I20260812 06:19:38.262043 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000007 (ops 32-36)
I20260812 06:19:38.262066 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000008 (ops 37-41)
I20260812 06:19:38.262089 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000009 (ops 42-46)
I20260812 06:19:38.262120 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000010 (ops 47-51)
I20260812 06:19:38.262143 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000011 (ops 52-56)
I20260812 06:19:38.262172 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000012 (ops 57-61)
I20260812 06:19:38.262195 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000013 (ops 62-66)
I20260812 06:19:38.283877 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: LogGCOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.022s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:19:38.284317 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=3.181125
I20260812 06:19:38.305343 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.021s	user 0.006s	sys 0.015s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4256,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:38.305908 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling UndoDeltaBlockGCOp(63137000980a444abd3565e5a1d89812): 462 bytes on disk
I20260812 06:19:38.306416 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: UndoDeltaBlockGCOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.306902 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:38.321024 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:38.321686 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:38.508793 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.187s	user 0.099s	sys 0.085s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1440,"lbm_read_time_us":14243,"lbm_reads_lt_1ms":674,"lbm_write_time_us":28915,"lbm_writes_lt_1ms":643,"mutex_wait_us":755,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:19:38.509410 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:38.577523 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.068s	user 0.032s	sys 0.036s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25882,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.578220 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:38.595180 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.595734 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:38.768814 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.173s	user 0.144s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":13246,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26040,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:19:38.769474 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:38.815744 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.046s	user 0.016s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19029,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.816392 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:38.840186 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.024s	user 0.007s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.840814 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:39.026789 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.186s	user 0.117s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":13774,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26415,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:39.027346 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:39.081226 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.054s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":24534,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.081820 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:39.094173 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4377,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.094715 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:39.263734 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.169s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":9711,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26699,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:19:39.264318 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:39.318023 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.054s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":25070,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.318709 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:39.330307 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.330879 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:39.475368 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.144s	user 0.119s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":10175,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27304,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:19:39.476034 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=11.118625
I20260812 06:19:39.512279 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.036s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14638,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.512835 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:39.537063 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.024s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3726,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.537633 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:39.547871 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.010s	user 0.006s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.548398 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:39.687856 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.139s	user 0.111s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":225,"lbm_read_time_us":9697,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26117,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:39.688479 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=11.118625
I20260812 06:19:39.716420 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.028s	user 0.016s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11609,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.717247 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:39.745101 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.028s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5507,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.745602 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:39.755795 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.756307 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushMRSOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:39.786309 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushMRSOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1141,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1610,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:39.787160 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling LogGCOp(63137000980a444abd3565e5a1d89812): free 136275181 bytes of WAL
I20260812 06:19:39.787428 20391 log_reader.cc:385] T 63137000980a444abd3565e5a1d89812: removed 13 log segments from log reader
I20260812 06:19:39.787482 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000014 (ops 67-71)
I20260812 06:19:39.787567 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000015 (ops 72-76)
I20260812 06:19:39.787604 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000016 (ops 77-81)
I20260812 06:19:39.787635 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000017 (ops 82-86)
I20260812 06:19:39.787667 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000018 (ops 87-91)
I20260812 06:19:39.787696 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000019 (ops 92-96)
I20260812 06:19:39.787726 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000020 (ops 97-101)
I20260812 06:19:39.787756 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000021 (ops 102-106)
I20260812 06:19:39.787786 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000022 (ops 107-111)
I20260812 06:19:39.787817 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000023 (ops 112-116)
I20260812 06:19:39.787847 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000024 (ops 117-120)
I20260812 06:19:39.787878 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000025 (ops 121-125)
I20260812 06:19:39.787906 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000026 (ops 126-130)
I20260812 06:19:39.813412 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: LogGCOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:39.813989 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=3.181125
I20260812 06:19:39.827634 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4703,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.828217 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:39.843729 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5297,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.844481 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling UndoDeltaBlockGCOp(63137000980a444abd3565e5a1d89812): 483 bytes on disk
I20260812 06:19:39.845197 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: UndoDeltaBlockGCOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.001s	user 0.001s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.846010 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:40.079814 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.234s	user 0.154s	sys 0.068s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979848,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1370,"lbm_read_time_us":14738,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36092,"lbm_writes_lt_1ms":743,"mutex_wait_us":674,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":34944,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:19:40.080506 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=15.087375
I20260812 06:19:40.139595 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.059s	user 0.033s	sys 0.022s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21799,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:40.140367 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:40.155438 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.015s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3761,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.155999 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:40.341989 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.186s	user 0.130s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":291,"lbm_read_time_us":12350,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31990,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:40.342612 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:40.401381 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.059s	user 0.042s	sys 0.014s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20348,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.402361 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:40.419680 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.017s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.420272 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:40.601261 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.181s	user 0.111s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":12906,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28293,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:19:40.602034 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=12.110812
I20260812 06:19:40.658926 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.057s	user 0.027s	sys 0.016s Metrics: {"bytes_written":13538210,"delete_count":0,"lbm_write_time_us":18965,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":332,"reinsert_count":0,"update_count":1650}
I20260812 06:19:40.659482 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=5.165500
I20260812 06:19:40.686306 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.027s	user 0.010s	sys 0.015s Metrics: {"bytes_written":6974360,"delete_count":0,"lbm_write_time_us":7851,"lbm_writes_lt_1ms":173,"reinsert_count":0,"update_count":850}
I20260812 06:19:40.686895 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:40.860352 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.173s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1466,"lbm_read_time_us":13343,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26957,"lbm_writes_lt_1ms":543,"mutex_wait_us":488,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2500}
I20260812 06:19:40.860891 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:40.908955 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.048s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21104,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.909780 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:40.928578 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.929198 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:41.088974 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.160s	user 0.111s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":174,"lbm_read_time_us":9169,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31471,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:19:41.089783 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:41.143854 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.054s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22417,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.144518 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:41.160324 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5925,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.161473 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:41.313180 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.151s	user 0.103s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":10018,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27883,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:19:41.313874 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=14.095187
I20260812 06:19:41.365736 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.052s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20773,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.366293 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=2.188937
I20260812 06:19:41.378086 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.378598 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushMRSOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:41.410785 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushMRSOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.032s	user 0.025s	sys 0.005s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1331,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2146,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:41.411623 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling LogGCOp(63137000980a444abd3565e5a1d89812): free 129773845 bytes of WAL
I20260812 06:19:41.411900 20391 log_reader.cc:385] T 63137000980a444abd3565e5a1d89812: removed 13 log segments from log reader
I20260812 06:19:41.411963 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000027 (ops 131-135)
I20260812 06:19:41.412003 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000028 (ops 136-140)
I20260812 06:19:41.412048 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000029 (ops 141-145)
I20260812 06:19:41.412079 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000030 (ops 146-150)
I20260812 06:19:41.412101 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000031 (ops 151-155)
I20260812 06:19:41.412132 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000032 (ops 156-160)
I20260812 06:19:41.412164 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000033 (ops 161-164)
I20260812 06:19:41.412186 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000034 (ops 165-169)
I20260812 06:19:41.412214 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000035 (ops 170-174)
I20260812 06:19:41.412240 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000036 (ops 175-179)
I20260812 06:19:41.412269 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000037 (ops 180-184)
I20260812 06:19:41.412302 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000038 (ops 185-189)
I20260812 06:19:41.412331 20391 log.cc:1079] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: Deleting log segment in path: /tmp/dist-test-taskS51XXe/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571359952-19921-0/minicluster-data/ts-0-root/wals/63137000980a444abd3565e5a1d89812/wal-000000039 (ops 190-194)
I20260812 06:19:41.439433 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: LogGCOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:41.439991 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling UndoDeltaBlockGCOp(63137000980a444abd3565e5a1d89812): 495 bytes on disk
I20260812 06:19:41.440450 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: UndoDeltaBlockGCOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.441095 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=4.173312
I20260812 06:19:41.455566 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":5907728,"delete_count":0,"lbm_write_time_us":5756,"lbm_writes_lt_1ms":147,"reinsert_count":0,"update_count":720}
I20260812 06:19:41.456099 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812): perf score=1.196750
I20260812 06:19:41.465211 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: FlushDeltaMemStoresOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2297554,"delete_count":0,"lbm_write_time_us":2827,"lbm_writes_lt_1ms":59,"reinsert_count":0,"update_count":280}
I20260812 06:19:41.465830 20493 maintenance_manager.cc:419] P e9466907e2c341a8975e7da60c2ff657: Scheduling MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812): perf score=1.000000
I20260812 06:19:41.564229 19921 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.776s	user 1.765s	sys 0.145s
I20260812 06:19:41.669018 19921 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.104s	user 0.000s	sys 0.000s
I20260812 06:19:41.669586 19921 tablet_server.cc:179] TabletServer@127.19.116.65:0 shutting down...
I20260812 06:19:41.682418 20391 maintenance_manager.cc:643] P e9466907e2c341a8975e7da60c2ff657: MajorDeltaCompactionOp(63137000980a444abd3565e5a1d89812) complete. Timing: real 0.216s	user 0.126s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979707,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":210,"lbm_read_time_us":16007,"lbm_reads_lt_1ms":770,"lbm_write_time_us":31796,"lbm_writes_lt_1ms":743,"mutex_wait_us":38,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7168,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:19:41.683461 19921 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:41.683727 19921 tablet_replica.cc:333] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657: stopping tablet replica
I20260812 06:19:41.683878 19921 raft_consensus.cc:2243] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:41.684058 19921 raft_consensus.cc:2272] T 63137000980a444abd3565e5a1d89812 P e9466907e2c341a8975e7da60c2ff657 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:41.701217 19921 tablet_server.cc:196] TabletServer@127.19.116.65:0 shutdown complete.
I20260812 06:19:41.740826 19921 master.cc:562] Master@127.19.116.126:35705 shutting down...
I20260812 06:19:41.743937 19921 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:41.744128 19921 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:41.744225 19921 tablet_replica.cc:333] T 00000000000000000000000000000000 P 293a23cd26474205b3c752bb8b93abfd: stopping tablet replica
I20260812 06:19:41.756835 19921 master.cc:584] Master@127.19.116.126:35705 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5245 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10461 ms total)

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