[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:14.190682 15247 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.227.254:36115
I20260812 06:20:14.191593 15247 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:14.192142 15247 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.198021 15258 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.198016 15247 server_base.cc:1061] running on GCE node
W20260812 06:20:14.198035 15252 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.198094 15254 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.198647 15247 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.198729 15247 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:14.198779 15247 hybrid_clock.cc:648] HybridClock initialized: now 1786515614198777 us; error 0 us; skew 500 ppm
I20260812 06:20:14.200277 15247 webserver.cc:533] Webserver started at http://127.14.227.254:38305/ using document root <none> and password file <none>
I20260812 06:20:14.200718 15247 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.200774 15247 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.200953 15247 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.202442 15247 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/master-0-root/instance:
uuid: "3c457b6f856543ff918a1d19b2d311ac"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-266d"
I20260812 06:20:14.205514 15247 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:14.207314 15266 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.208204 15247 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:14.208298 15247 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/master-0-root
uuid: "3c457b6f856543ff918a1d19b2d311ac"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-266d"
I20260812 06:20:14.208382 15247 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:14.237440 15247 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:14.238024 15247 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:14.238174 15247 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:14.245205 15247 rpc_server.cc:307] RPC server started. Bound to: 127.14.227.254:36115
I20260812 06:20:14.245210 15358 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.227.254:36115 every 8 connection(s)
I20260812 06:20:14.247318 15359 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:14.252498 15359 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac: Bootstrap starting.
I20260812 06:20:14.254854 15359 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.255692 15359 log.cc:826] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:14.257254 15359 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac: No bootstrap required, opened a new log
I20260812 06:20:14.259867 15359 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c457b6f856543ff918a1d19b2d311ac" member_type: VOTER }
I20260812 06:20:14.260023 15359 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.260092 15359 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3c457b6f856543ff918a1d19b2d311ac, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.260618 15359 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [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: "3c457b6f856543ff918a1d19b2d311ac" member_type: VOTER }
I20260812 06:20:14.260753 15359 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.260828 15359 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.260946 15359 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.261659 15359 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c457b6f856543ff918a1d19b2d311ac" member_type: VOTER }
I20260812 06:20:14.262061 15359 leader_election.cc:304] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [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: 3c457b6f856543ff918a1d19b2d311ac; no voters: 
I20260812 06:20:14.262355 15359 leader_election.cc:290] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.262446 15368 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.262646 15368 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 1 LEADER]: Becoming Leader. State: Replica: 3c457b6f856543ff918a1d19b2d311ac, State: Running, Role: LEADER
I20260812 06:20:14.263042 15368 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [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: "3c457b6f856543ff918a1d19b2d311ac" member_type: VOTER }
I20260812 06:20:14.263265 15359 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:14.264771 15370 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3c457b6f856543ff918a1d19b2d311ac. Latest consensus state: current_term: 1 leader_uuid: "3c457b6f856543ff918a1d19b2d311ac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c457b6f856543ff918a1d19b2d311ac" member_type: VOTER } }
I20260812 06:20:14.264796 15369 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3c457b6f856543ff918a1d19b2d311ac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c457b6f856543ff918a1d19b2d311ac" member_type: VOTER } }
I20260812 06:20:14.264911 15369 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:14.264909 15370 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:14.265385 15383 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:14.265472 15247 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:14.267513 15383 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:14.271811 15383 catalog_manager.cc:1383] Generated new cluster ID: 0e081ea0c9f643c7a9001c3460ad4933
I20260812 06:20:14.271871 15383 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:14.284969 15383 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:14.286036 15383 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:14.299634 15383 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac: Generated new TSK 0
I20260812 06:20:14.300288 15383 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:14.330395 15247 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.332860 15395 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.332899 15400 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.333046 15247 server_base.cc:1061] running on GCE node
W20260812 06:20:14.332917 15398 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.333374 15247 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.333426 15247 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:14.333459 15247 hybrid_clock.cc:648] HybridClock initialized: now 1786515614333458 us; error 0 us; skew 500 ppm
I20260812 06:20:14.334285 15247 webserver.cc:533] Webserver started at http://127.14.227.193:38463/ using document root <none> and password file <none>
I20260812 06:20:14.334451 15247 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.334499 15247 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.334574 15247 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.334942 15247 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/instance:
uuid: "e2d95f32b7b34e8aad147a8f8faa8127"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-266d"
I20260812 06:20:14.336443 15247 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:14.337375 15407 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.337612 15247 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:14.337682 15247 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root
uuid: "e2d95f32b7b34e8aad147a8f8faa8127"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-266d"
I20260812 06:20:14.337749 15247 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:14.351209 15247 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:14.351567 15247 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:14.351981 15247 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:14.352797 15247 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:14.352849 15247 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.352893 15247 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:14.352923 15247 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.359166 15247 rpc_server.cc:307] RPC server started. Bound to: 127.14.227.193:36153
I20260812 06:20:14.359226 15513 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.227.193:36153 every 8 connection(s)
I20260812 06:20:14.368124 15514 heartbeater.cc:344] Connected to a master server at 127.14.227.254:36115
I20260812 06:20:14.368335 15514 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:14.368745 15514 heartbeater.cc:507] Master 127.14.227.254:36115 requested a full tablet report, sending...
I20260812 06:20:14.370184 15302 ts_manager.cc:194] Registered new tserver with Master: e2d95f32b7b34e8aad147a8f8faa8127 (127.14.227.193:36153)
I20260812 06:20:14.370846 15247 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011089651s
I20260812 06:20:14.371572 15302 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39466
I20260812 06:20:14.379129 15302 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39480:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:14.391515 15451 tablet_service.cc:1511] Processing CreateTablet for tablet 3c988d08517741c78f16728f61f4b4ed (DEFAULT_TABLE table=heavy-update-compaction-test [id=4619ebee929b4f2090d6507f87fd1ee0]), partition=
I20260812 06:20:14.391937 15451 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3c988d08517741c78f16728f61f4b4ed. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:14.394259 15539 tablet_bootstrap.cc:492] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Bootstrap starting.
I20260812 06:20:14.395183 15539 tablet_bootstrap.cc:654] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.396653 15539 tablet_bootstrap.cc:492] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: No bootstrap required, opened a new log
I20260812 06:20:14.396766 15539 ts_tablet_manager.cc:1403] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:14.397358 15539 raft_consensus.cc:359] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2d95f32b7b34e8aad147a8f8faa8127" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 36153 } }
I20260812 06:20:14.397485 15539 raft_consensus.cc:385] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.397534 15539 raft_consensus.cc:740] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e2d95f32b7b34e8aad147a8f8faa8127, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.397671 15539 consensus_queue.cc:260] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [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: "e2d95f32b7b34e8aad147a8f8faa8127" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 36153 } }
I20260812 06:20:14.397774 15539 raft_consensus.cc:399] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.397822 15539 raft_consensus.cc:493] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.397873 15539 raft_consensus.cc:3060] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.398819 15539 raft_consensus.cc:515] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2d95f32b7b34e8aad147a8f8faa8127" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 36153 } }
I20260812 06:20:14.398964 15539 leader_election.cc:304] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [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: e2d95f32b7b34e8aad147a8f8faa8127; no voters: 
I20260812 06:20:14.399178 15539 leader_election.cc:290] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.399276 15541 raft_consensus.cc:2804] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.399485 15541 raft_consensus.cc:697] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 1 LEADER]: Becoming Leader. State: Replica: e2d95f32b7b34e8aad147a8f8faa8127, State: Running, Role: LEADER
I20260812 06:20:14.399523 15539 ts_tablet_manager.cc:1434] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:14.399626 15541 consensus_queue.cc:237] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [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: "e2d95f32b7b34e8aad147a8f8faa8127" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 36153 } }
I20260812 06:20:14.399906 15514 heartbeater.cc:499] Master 127.14.227.254:36115 was elected leader, sending a full tablet report...
I20260812 06:20:14.402393 15302 catalog_manager.cc:5719] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 reported cstate change: term changed from 0 to 1, leader changed from <none> to e2d95f32b7b34e8aad147a8f8faa8127 (127.14.227.193). New cstate: current_term: 1 leader_uuid: "e2d95f32b7b34e8aad147a8f8faa8127" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2d95f32b7b34e8aad147a8f8faa8127" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 36153 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:14.458562 15247 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.017s	sys 0.008s
I20260812 06:20:14.610131 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushMRSOp(3c988d08517741c78f16728f61f4b4ed): perf score=23.023690
I20260812 06:20:14.788393 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushMRSOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.178s	user 0.143s	sys 0.024s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":195,"delete_count":0,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":860,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43241,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":124,"threads_started":1,"update_count":1500}
I20260812 06:20:14.789533 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling LogGCOp(3c988d08517741c78f16728f61f4b4ed): free 20743880 bytes of WAL
I20260812 06:20:14.789849 15413 log_reader.cc:385] T 3c988d08517741c78f16728f61f4b4ed: removed 2 log segments from log reader
I20260812 06:20:14.789924 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000001 (ops 1-6)
I20260812 06:20:14.789981 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000002 (ops 7-11)
I20260812 06:20:14.795084 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: LogGCOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:14.795431 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling UndoDeltaBlockGCOp(3c988d08517741c78f16728f61f4b4ed): 20513818 bytes on disk
I20260812 06:20:14.795984 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: UndoDeltaBlockGCOp(3c988d08517741c78f16728f61f4b4ed) 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:20:14.796414 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:14.809605 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.810117 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:14.949522 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.139s	user 0.087s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":9159,"lbm_reads_lt_1ms":460,"lbm_write_time_us":22043,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":309,"threads_started":5,"update_count":2000}
I20260812 06:20:14.950018 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:14.991361 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.041s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16754,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.991730 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:15.003746 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.004179 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:15.118052 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.114s	user 0.097s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":360,"lbm_read_time_us":7167,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22694,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:20:15.118606 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:15.154747 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.036s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12573,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.155246 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:15.165637 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.166061 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:15.276024 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.110s	user 0.082s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":8009,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20016,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:20:15.276528 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:15.322651 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.046s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12307487,"delete_count":0,"lbm_write_time_us":14446,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.323194 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:15.332861 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.333365 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:15.468001 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.134s	user 0.100s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":458,"lbm_read_time_us":9915,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20276,"lbm_writes_lt_1ms":443,"mutex_wait_us":261,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":31360,"update_count":2000}
I20260812 06:20:15.468568 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:15.510946 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.042s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13866,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.511411 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:15.521445 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.522073 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:15.641922 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.120s	user 0.083s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":664,"lbm_read_time_us":8936,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21643,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:20:15.642501 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:15.673141 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.030s	user 0.026s	sys 0.003s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12740,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.673671 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:15.684161 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.684791 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:15.805480 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.120s	user 0.088s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":745,"lbm_read_time_us":9190,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22312,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:15.805938 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:15.855827 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.050s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16010,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.856308 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:15.866047 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.866415 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushMRSOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:15.894232 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushMRSOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1201,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1504,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:15.895068 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling UndoDeltaBlockGCOp(3c988d08517741c78f16728f61f4b4ed): 447 bytes on disk
I20260812 06:20:15.895430 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: UndoDeltaBlockGCOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.895880 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:16.024518 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.128s	user 0.083s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":7488,"lbm_reads_lt_1ms":464,"lbm_write_time_us":19906,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:20:16.025058 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling LogGCOp(3c988d08517741c78f16728f61f4b4ed): free 115943172 bytes of WAL
I20260812 06:20:16.025310 15413 log_reader.cc:385] T 3c988d08517741c78f16728f61f4b4ed: removed 11 log segments from log reader
I20260812 06:20:16.025360 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000003 (ops 12-16)
I20260812 06:20:16.025396 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000004 (ops 17-21)
I20260812 06:20:16.025419 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000005 (ops 22-26)
I20260812 06:20:16.025441 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000006 (ops 27-31)
I20260812 06:20:16.025462 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000007 (ops 32-36)
I20260812 06:20:16.025484 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000008 (ops 37-41)
I20260812 06:20:16.025506 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000009 (ops 42-46)
I20260812 06:20:16.025525 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000010 (ops 47-51)
I20260812 06:20:16.025549 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000011 (ops 52-56)
I20260812 06:20:16.025576 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000012 (ops 57-61)
I20260812 06:20:16.025599 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000013 (ops 62-66)
I20260812 06:20:16.044111 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: LogGCOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.019s	user 0.004s	sys 0.012s Metrics: {}
I20260812 06:20:16.044513 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=14.095187
I20260812 06:20:16.086913 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.042s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18856,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.087394 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:16.098067 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.011s	user 0.005s	sys 0.004s 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:20:16.098487 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:16.266232 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.168s	user 0.100s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":9396,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27640,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:16.266664 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=14.095187
I20260812 06:20:16.313249 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.046s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18378,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.313715 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:16.323540 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3669,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.324036 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:16.481202 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.157s	user 0.115s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":10501,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27105,"lbm_writes_lt_1ms":543,"mutex_wait_us":295,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:20:16.481828 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=14.095187
I20260812 06:20:16.536136 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.054s	user 0.018s	sys 0.030s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.536751 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:16.546833 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.547361 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:16.680003 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.132s	user 0.111s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":523,"lbm_read_time_us":11674,"lbm_reads_lt_1ms":572,"lbm_write_time_us":23663,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:20:16.680542 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:16.718792 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.038s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16203,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.719271 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:16.818853 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.099s	user 0.085s	sys 0.010s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":595,"lbm_read_time_us":7177,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17081,"lbm_writes_lt_1ms":343,"mutex_wait_us":291,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":1500}
I20260812 06:20:16.819461 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:16.864363 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.045s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15260,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.864894 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:16.879506 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.880030 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:16.997340 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.117s	user 0.090s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":122,"lbm_read_time_us":7645,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22619,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:16.997831 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:17.040915 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.043s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13505,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.041534 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:17.050866 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.051640 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:17.165195 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.113s	user 0.097s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":932,"lbm_read_time_us":7697,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21586,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2000}
I20260812 06:20:17.165843 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:17.198597 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.032s	user 0.012s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12517,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.199057 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:17.213233 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.014s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.213862 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushMRSOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:17.241755 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushMRSOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.028s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":1328,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1428,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:17.242522 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling LogGCOp(3c988d08517741c78f16728f61f4b4ed): free 121459489 bytes of WAL
I20260812 06:20:17.242733 15413 log_reader.cc:385] T 3c988d08517741c78f16728f61f4b4ed: removed 12 log segments from log reader
I20260812 06:20:17.242797 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000014 (ops 67-71)
I20260812 06:20:17.242835 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000015 (ops 72-76)
I20260812 06:20:17.242864 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000016 (ops 77-81)
I20260812 06:20:17.242895 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000017 (ops 82-86)
I20260812 06:20:17.242929 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000018 (ops 87-91)
I20260812 06:20:17.242959 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000019 (ops 92-96)
I20260812 06:20:17.242986 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000020 (ops 97-101)
I20260812 06:20:17.243014 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000021 (ops 102-106)
I20260812 06:20:17.243041 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000022 (ops 107-111)
I20260812 06:20:17.243073 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000023 (ops 112-116)
I20260812 06:20:17.243104 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000024 (ops 117-121)
I20260812 06:20:17.243131 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000025 (ops 122-126)
I20260812 06:20:17.268376 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: LogGCOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:17.268784 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling UndoDeltaBlockGCOp(3c988d08517741c78f16728f61f4b4ed): 472 bytes on disk
I20260812 06:20:17.269232 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: UndoDeltaBlockGCOp(3c988d08517741c78f16728f61f4b4ed) 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:20:17.269842 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=3.181125
I20260812 06:20:17.280999 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":3883,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:17.281378 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling LogGCOp(3c988d08517741c78f16728f61f4b4ed): free 11564883 bytes of WAL
I20260812 06:20:17.281553 15413 log_reader.cc:385] T 3c988d08517741c78f16728f61f4b4ed: removed 1 log segments from log reader
I20260812 06:20:17.281596 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000026 (ops 127-130)
I20260812 06:20:17.283360 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: LogGCOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:17.283620 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:17.292539 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3166,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.292970 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:17.452001 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.159s	user 0.104s	sys 0.053s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":144,"lbm_read_time_us":10393,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31333,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:20:17.452955 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=14.095187
I20260812 06:20:17.500334 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.047s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409879,"delete_count":0,"lbm_write_time_us":19225,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.500865 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:17.510406 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3578,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.510802 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:17.653332 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.142s	user 0.108s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815661,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":10972,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25385,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:20:17.654255 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=12.110812
I20260812 06:20:17.688138 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.034s	user 0.022s	sys 0.009s Metrics: {"bytes_written":13579240,"delete_count":0,"lbm_write_time_us":14295,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:20:17.688603 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.196750
I20260812 06:20:17.698289 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3259,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:20:17.698705 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:17.838872 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.140s	user 0.089s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713243,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":35,"lbm_read_time_us":8765,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23841,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:20:17.839387 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:17.870352 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.031s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13120,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.870867 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:17.886754 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.887252 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:18.012303 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.125s	user 0.079s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":8595,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23043,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:20:18.012986 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:18.047005 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.034s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13461,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.047591 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:18.057540 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.057960 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:18.177831 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.120s	user 0.104s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":119,"lbm_read_time_us":7550,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25017,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:20:18.178426 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:18.218638 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.040s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16378,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.219170 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:18.235280 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.235780 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:18.356701 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.121s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":69,"lbm_read_time_us":9520,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22598,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:18.357499 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=10.126437
I20260812 06:20:18.404906 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.045s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17812,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.405469 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:18.416792 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.417302 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:18.553580 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.136s	user 0.102s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":10083,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23586,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:18.554078 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=11.118625
I20260812 06:20:18.587139 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13863,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.587675 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=2.188937
I20260812 06:20:18.600047 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4699,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.600471 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushMRSOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:18.629969 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushMRSOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1269,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1345,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:18.630749 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling LogGCOp(3c988d08517741c78f16728f61f4b4ed): free 117302835 bytes of WAL
I20260812 06:20:18.631079 15413 log_reader.cc:385] T 3c988d08517741c78f16728f61f4b4ed: removed 12 log segments from log reader
I20260812 06:20:18.631198 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000027 (ops 131-135)
I20260812 06:20:18.631279 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000028 (ops 136-140)
I20260812 06:20:18.631330 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000029 (ops 141-144)
I20260812 06:20:18.631385 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000030 (ops 145-149)
I20260812 06:20:18.631433 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000031 (ops 150-154)
I20260812 06:20:18.631479 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000032 (ops 155-158)
I20260812 06:20:18.631523 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000033 (ops 159-163)
I20260812 06:20:18.631593 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000034 (ops 164-168)
I20260812 06:20:18.631639 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000035 (ops 169-173)
I20260812 06:20:18.631678 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000036 (ops 174-178)
I20260812 06:20:18.631721 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000037 (ops 179-183)
I20260812 06:20:18.631759 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000038 (ops 184-188)
I20260812 06:20:18.650695 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: LogGCOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:20:18.651213 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling UndoDeltaBlockGCOp(3c988d08517741c78f16728f61f4b4ed): 482 bytes on disk
I20260812 06:20:18.651628 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: UndoDeltaBlockGCOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.652266 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=5.165500
I20260812 06:20:18.674013 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.022s	user 0.017s	sys 0.004s Metrics: {"bytes_written":7097424,"delete_count":0,"lbm_write_time_us":8979,"lbm_writes_lt_1ms":176,"reinsert_count":0,"update_count":865}
I20260812 06:20:18.674430 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling LogGCOp(3c988d08517741c78f16728f61f4b4ed): free 11564893 bytes of WAL
I20260812 06:20:18.674651 15413 log_reader.cc:385] T 3c988d08517741c78f16728f61f4b4ed: removed 1 log segments from log reader
I20260812 06:20:18.674715 15413 log.cc:1079] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/3c988d08517741c78f16728f61f4b4ed/wal-000000039 (ops 189-192)
I20260812 06:20:18.677639 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: LogGCOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:18.677932 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed): perf score=1.000000
I20260812 06:20:18.873663 15247 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.415s	user 1.663s	sys 0.114s
I20260812 06:20:18.876904 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: MajorDeltaCompactionOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.199s	user 0.120s	sys 0.068s Metrics: {"cfile_cache_miss":606,"cfile_cache_miss_bytes":27810554,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":914,"lbm_read_time_us":12489,"lbm_reads_lt_1ms":642,"lbm_write_time_us":32459,"lbm_writes_lt_1ms":616,"mutex_wait_us":536,"peak_mem_usage":71313375,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":63,"threads_started":1,"update_count":2865}
I20260812 06:20:18.878448 15519 maintenance_manager.cc:419] P e2d95f32b7b34e8aad147a8f8faa8127: Scheduling FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed): perf score=15.087375
I20260812 06:20:18.899298 15247 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.025s	user 0.001s	sys 0.000s
I20260812 06:20:18.899901 15247 tablet_server.cc:179] TabletServer@127.14.227.193:0 shutting down...
I20260812 06:20:18.923658 15413 maintenance_manager.cc:643] P e2d95f32b7b34e8aad147a8f8faa8127: FlushDeltaMemStoresOp(3c988d08517741c78f16728f61f4b4ed) complete. Timing: real 0.045s	user 0.013s	sys 0.029s Metrics: {"bytes_written":17517554,"delete_count":0,"lbm_write_time_us":18425,"lbm_writes_lt_1ms":430,"reinsert_count":0,"update_count":2135}
I20260812 06:20:18.924213 15247 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:18.924563 15247 tablet_replica.cc:333] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127: stopping tablet replica
I20260812 06:20:18.924769 15247 raft_consensus.cc:2243] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:18.924971 15247 raft_consensus.cc:2272] T 3c988d08517741c78f16728f61f4b4ed P e2d95f32b7b34e8aad147a8f8faa8127 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:18.949573 15247 tablet_server.cc:196] TabletServer@127.14.227.193:0 shutdown complete.
I20260812 06:20:18.953917 15247 master.cc:562] Master@127.14.227.254:36115 shutting down...
I20260812 06:20:18.958534 15247 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:18.958670 15247 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:18.958739 15247 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3c457b6f856543ff918a1d19b2d311ac: stopping tablet replica
I20260812 06:20:18.970584 15247 master.cc:584] Master@127.14.227.254:36115 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4854 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:19.044759 15247 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.227.254:37415
I20260812 06:20:19.045166 15247 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.047000 15574 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.047079 15570 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.047093 15571 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.047398 15247 server_base.cc:1061] running on GCE node
I20260812 06:20:19.047544 15247 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.047577 15247 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.047591 15247 hybrid_clock.cc:648] HybridClock initialized: now 1786515619047591 us; error 0 us; skew 500 ppm
I20260812 06:20:19.048307 15247 webserver.cc:533] Webserver started at http://127.14.227.254:44155/ using document root <none> and password file <none>
I20260812 06:20:19.048435 15247 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.048478 15247 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.048535 15247 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.048870 15247 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/master-0-root/instance:
uuid: "c8e29f18ebfb45388e0128866ddb707e"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-266d"
I20260812 06:20:19.050254 15247 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:19.051080 15581 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.051286 15247 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.051358 15247 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/master-0-root
uuid: "c8e29f18ebfb45388e0128866ddb707e"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-266d"
I20260812 06:20:19.051424 15247 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.068308 15247 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.068612 15247 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.072499 15247 rpc_server.cc:307] RPC server started. Bound to: 127.14.227.254:37415
I20260812 06:20:19.076247 15675 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.227.254:37415 every 8 connection(s)
I20260812 06:20:19.076682 15679 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.078348 15679 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e: Bootstrap starting.
I20260812 06:20:19.079043 15679 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.079911 15679 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e: No bootstrap required, opened a new log
I20260812 06:20:19.080248 15679 raft_consensus.cc:359] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8e29f18ebfb45388e0128866ddb707e" member_type: VOTER }
I20260812 06:20:19.080324 15679 raft_consensus.cc:385] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.080344 15679 raft_consensus.cc:740] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c8e29f18ebfb45388e0128866ddb707e, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.080443 15679 consensus_queue.cc:260] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [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: "c8e29f18ebfb45388e0128866ddb707e" member_type: VOTER }
I20260812 06:20:19.080500 15679 raft_consensus.cc:399] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.080525 15679 raft_consensus.cc:493] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.080556 15679 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.081200 15679 raft_consensus.cc:515] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8e29f18ebfb45388e0128866ddb707e" member_type: VOTER }
I20260812 06:20:19.081310 15679 leader_election.cc:304] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [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: c8e29f18ebfb45388e0128866ddb707e; no voters: 
I20260812 06:20:19.081444 15679 leader_election.cc:290] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.081555 15692 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.081733 15692 raft_consensus.cc:697] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 1 LEADER]: Becoming Leader. State: Replica: c8e29f18ebfb45388e0128866ddb707e, State: Running, Role: LEADER
I20260812 06:20:19.081873 15679 sys_catalog.cc:565] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.081875 15692 consensus_queue.cc:237] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [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: "c8e29f18ebfb45388e0128866ddb707e" member_type: VOTER }
I20260812 06:20:19.082314 15693 sys_catalog.cc:455] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c8e29f18ebfb45388e0128866ddb707e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8e29f18ebfb45388e0128866ddb707e" member_type: VOTER } }
I20260812 06:20:19.082352 15696 sys_catalog.cc:455] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [sys.catalog]: SysCatalogTable state changed. Reason: New leader c8e29f18ebfb45388e0128866ddb707e. Latest consensus state: current_term: 1 leader_uuid: "c8e29f18ebfb45388e0128866ddb707e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8e29f18ebfb45388e0128866ddb707e" member_type: VOTER } }
I20260812 06:20:19.082466 15693 sys_catalog.cc:458] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.082484 15696 sys_catalog.cc:458] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.082947 15702 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.083818 15702 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.084031 15247 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:19.085529 15702 catalog_manager.cc:1383] Generated new cluster ID: 919fd413ca7540c69e7b62a42cb0446d
I20260812 06:20:19.085584 15702 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.098287 15702 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.098784 15702 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.102732 15702 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e: Generated new TSK 0
I20260812 06:20:19.102875 15702 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.116035 15247 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.117722 15722 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.117730 15720 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.117789 15726 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.117978 15247 server_base.cc:1061] running on GCE node
I20260812 06:20:19.118126 15247 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.118163 15247 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.118187 15247 hybrid_clock.cc:648] HybridClock initialized: now 1786515619118187 us; error 0 us; skew 500 ppm
I20260812 06:20:19.118944 15247 webserver.cc:533] Webserver started at http://127.14.227.193:42933/ using document root <none> and password file <none>
I20260812 06:20:19.119078 15247 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.119130 15247 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.119202 15247 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.119520 15247 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/instance:
uuid: "e7fdf68178a34d70be1ebbd1ead52cfe"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-266d"
I20260812 06:20:19.120843 15247 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:19.121743 15735 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.121976 15247 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.122038 15247 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root
uuid: "e7fdf68178a34d70be1ebbd1ead52cfe"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-266d"
I20260812 06:20:19.122103 15247 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.128917 15247 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.129222 15247 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.129467 15247 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.129859 15247 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.129895 15247 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.129933 15247 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.129961 15247 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.133764 15247 rpc_server.cc:307] RPC server started. Bound to: 127.14.227.193:43993
I20260812 06:20:19.135633 15839 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.227.193:43993 every 8 connection(s)
I20260812 06:20:19.142783 15840 heartbeater.cc:344] Connected to a master server at 127.14.227.254:37415
I20260812 06:20:19.142869 15840 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.143049 15840 heartbeater.cc:507] Master 127.14.227.254:37415 requested a full tablet report, sending...
I20260812 06:20:19.143632 15613 ts_manager.cc:194] Registered new tserver with Master: e7fdf68178a34d70be1ebbd1ead52cfe (127.14.227.193:43993)
I20260812 06:20:19.144119 15247 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009749689s
I20260812 06:20:19.144321 15613 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36566
I20260812 06:20:19.150060 15613 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36580:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:19.157737 15782 tablet_service.cc:1511] Processing CreateTablet for tablet 0d5f2cfdef6c420b903dbfce5f078db7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=23c3910fd8e741639a1db74d8b6058a3]), partition=
I20260812 06:20:19.157959 15782 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0d5f2cfdef6c420b903dbfce5f078db7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.159700 15864 tablet_bootstrap.cc:492] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Bootstrap starting.
I20260812 06:20:19.160576 15864 tablet_bootstrap.cc:654] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.161545 15864 tablet_bootstrap.cc:492] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: No bootstrap required, opened a new log
I20260812 06:20:19.161616 15864 ts_tablet_manager.cc:1403] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:19.162003 15864 raft_consensus.cc:359] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7fdf68178a34d70be1ebbd1ead52cfe" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 43993 } }
I20260812 06:20:19.162081 15864 raft_consensus.cc:385] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.162112 15864 raft_consensus.cc:740] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e7fdf68178a34d70be1ebbd1ead52cfe, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.162235 15864 consensus_queue.cc:260] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [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: "e7fdf68178a34d70be1ebbd1ead52cfe" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 43993 } }
I20260812 06:20:19.162303 15864 raft_consensus.cc:399] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.162338 15864 raft_consensus.cc:493] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.162386 15864 raft_consensus.cc:3060] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.163058 15864 raft_consensus.cc:515] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7fdf68178a34d70be1ebbd1ead52cfe" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 43993 } }
I20260812 06:20:19.163195 15864 leader_election.cc:304] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [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: e7fdf68178a34d70be1ebbd1ead52cfe; no voters: 
I20260812 06:20:19.163384 15864 leader_election.cc:290] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.163487 15866 raft_consensus.cc:2804] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.163682 15840 heartbeater.cc:499] Master 127.14.227.254:37415 was elected leader, sending a full tablet report...
I20260812 06:20:19.163754 15866 raft_consensus.cc:697] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 1 LEADER]: Becoming Leader. State: Replica: e7fdf68178a34d70be1ebbd1ead52cfe, State: Running, Role: LEADER
I20260812 06:20:19.163903 15864 ts_tablet_manager.cc:1434] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:19.163893 15866 consensus_queue.cc:237] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [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: "e7fdf68178a34d70be1ebbd1ead52cfe" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 43993 } }
I20260812 06:20:19.165046 15613 catalog_manager.cc:5719] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe reported cstate change: term changed from 0 to 1, leader changed from <none> to e7fdf68178a34d70be1ebbd1ead52cfe (127.14.227.193). New cstate: current_term: 1 leader_uuid: "e7fdf68178a34d70be1ebbd1ead52cfe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e7fdf68178a34d70be1ebbd1ead52cfe" member_type: VOTER last_known_addr { host: "127.14.227.193" port: 43993 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.217540 15247 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.008s	sys 0.014s
I20260812 06:20:19.386057 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushMRSOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=23.023690
I20260812 06:20:19.535957 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushMRSOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.150s	user 0.115s	sys 0.032s Metrics: {"bytes_written":13292061,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":809,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39944,"lbm_writes_lt_1ms":881,"mutex_wait_us":147,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1920,"update_count":1620}
I20260812 06:20:19.536665 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling LogGCOp(0d5f2cfdef6c420b903dbfce5f078db7): free 20743880 bytes of WAL
I20260812 06:20:19.536938 15741 log_reader.cc:385] T 0d5f2cfdef6c420b903dbfce5f078db7: removed 2 log segments from log reader
I20260812 06:20:19.536988 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000001 (ops 1-6)
I20260812 06:20:19.537025 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000002 (ops 7-11)
I20260812 06:20:19.540652 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: LogGCOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:19.541075 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling UndoDeltaBlockGCOp(0d5f2cfdef6c420b903dbfce5f078db7): 20513815 bytes on disk
I20260812 06:20:19.541522 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: UndoDeltaBlockGCOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.541870 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:19.553896 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.012s	user 0.006s	sys 0.002s Metrics: {"bytes_written":3528309,"delete_count":0,"lbm_write_time_us":3000,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:20:19.554275 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:19.563342 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3382,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.563723 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:19.744900 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.181s	user 0.121s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815770,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":505,"lbm_read_time_us":11175,"lbm_reads_lt_1ms":569,"lbm_write_time_us":33569,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":323,"threads_started":5,"update_count":2500}
I20260812 06:20:19.745517 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:19.792966 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.047s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21385,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.793433 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:19.940124 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.147s	user 0.090s	sys 0.057s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":179,"lbm_read_time_us":9609,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25126,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:19.940653 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:19.993662 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.053s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23883,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.994186 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:20.006513 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4367,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.006975 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:20.194765 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.188s	user 0.110s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":12423,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32170,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:20:20.195257 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:20.247740 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.052s	user 0.041s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23052,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.248433 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:20.269641 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.270044 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:20.287861 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.018s	user 0.000s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3460,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.288316 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:20.484773 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.196s	user 0.132s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918212,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":568,"lbm_read_time_us":12478,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34646,"lbm_writes_lt_1ms":643,"mutex_wait_us":216,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3000}
I20260812 06:20:20.485381 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:20.537355 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.052s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17722,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.537889 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:20.547964 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.548331 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:20.731314 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.183s	user 0.102s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":12482,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27363,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27520,"update_count":2500}
I20260812 06:20:20.731961 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:20.790464 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.058s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28258,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.790993 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:20.802917 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4569,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.803370 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushMRSOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:20.834892 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushMRSOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.031s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1306,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1341,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:20.835574 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling LogGCOp(0d5f2cfdef6c420b903dbfce5f078db7): free 124710289 bytes of WAL
I20260812 06:20:20.835822 15741 log_reader.cc:385] T 0d5f2cfdef6c420b903dbfce5f078db7: removed 12 log segments from log reader
I20260812 06:20:20.835870 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000003 (ops 12-16)
I20260812 06:20:20.835898 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000004 (ops 17-21)
I20260812 06:20:20.835916 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000005 (ops 22-26)
I20260812 06:20:20.835947 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000006 (ops 27-31)
I20260812 06:20:20.835981 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000007 (ops 32-36)
I20260812 06:20:20.836014 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000008 (ops 37-41)
I20260812 06:20:20.836035 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000009 (ops 42-46)
I20260812 06:20:20.836064 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000010 (ops 47-51)
I20260812 06:20:20.836097 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000011 (ops 52-56)
I20260812 06:20:20.836127 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000012 (ops 57-61)
I20260812 06:20:20.836158 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000013 (ops 62-66)
I20260812 06:20:20.836189 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000014 (ops 67-71)
I20260812 06:20:20.859373 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: LogGCOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:20.859736 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=3.181125
I20260812 06:20:20.873436 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":3770,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:20.873859 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling UndoDeltaBlockGCOp(0d5f2cfdef6c420b903dbfce5f078db7): 472 bytes on disk
I20260812 06:20:20.874231 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: UndoDeltaBlockGCOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.874701 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:20.883335 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3145,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.883749 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:21.092372 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.208s	user 0.127s	sys 0.078s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1322,"lbm_read_time_us":12808,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33050,"lbm_writes_lt_1ms":743,"mutex_wait_us":449,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14592,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:20:21.093338 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=18.063937
I20260812 06:20:21.152587 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.059s	user 0.022s	sys 0.022s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":21011,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:21.153082 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:21.168661 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6071,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.169135 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:21.367274 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.198s	user 0.137s	sys 0.057s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":253,"lbm_read_time_us":13248,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32364,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":3000}
I20260812 06:20:21.368294 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=16.079562
I20260812 06:20:21.430052 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.062s	user 0.037s	sys 0.019s Metrics: {"bytes_written":17681651,"delete_count":0,"lbm_write_time_us":27059,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2155}
I20260812 06:20:21.430593 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=5.165500
I20260812 06:20:21.453958 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.023s	user 0.015s	sys 0.005s Metrics: {"bytes_written":6933333,"delete_count":0,"lbm_write_time_us":8550,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:20:21.454433 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:21.654417 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.200s	user 0.084s	sys 0.108s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":14015,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32817,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":3000}
I20260812 06:20:21.654994 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=18.063937
I20260812 06:20:21.720670 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.065s	user 0.031s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24322,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:21.721179 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:21.731743 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.732323 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:21.926431 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.194s	user 0.141s	sys 0.050s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":14660,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29910,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:20:21.927063 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=16.079562
I20260812 06:20:21.973441 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":17763698,"delete_count":0,"lbm_write_time_us":18975,"lbm_writes_lt_1ms":436,"reinsert_count":0,"update_count":2165}
I20260812 06:20:21.973907 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.196750
I20260812 06:20:21.983906 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":3361,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:20:21.984308 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:21.992945 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3269,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.993316 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:22.182240 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.189s	user 0.126s	sys 0.062s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918182,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":217,"lbm_read_time_us":12533,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32478,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:20:22.182822 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:22.231433 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.046s	user 0.013s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16793,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.231956 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:22.242161 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.242735 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushMRSOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:22.270814 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushMRSOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1186,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1434,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:22.271456 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling LogGCOp(0d5f2cfdef6c420b903dbfce5f078db7): free 128867483 bytes of WAL
I20260812 06:20:22.271706 15741 log_reader.cc:385] T 0d5f2cfdef6c420b903dbfce5f078db7: removed 13 log segments from log reader
I20260812 06:20:22.271767 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000015 (ops 72-76)
I20260812 06:20:22.271816 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000016 (ops 77-80)
I20260812 06:20:22.271850 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000017 (ops 81-85)
I20260812 06:20:22.271873 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000018 (ops 86-90)
I20260812 06:20:22.271900 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000019 (ops 91-94)
I20260812 06:20:22.271927 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000020 (ops 95-99)
I20260812 06:20:22.271960 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000021 (ops 100-104)
I20260812 06:20:22.271994 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000022 (ops 105-108)
I20260812 06:20:22.272017 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000023 (ops 109-113)
I20260812 06:20:22.272037 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000024 (ops 114-118)
I20260812 06:20:22.272058 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000025 (ops 119-123)
I20260812 06:20:22.272140 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000026 (ops 124-128)
I20260812 06:20:22.272183 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000027 (ops 129-133)
I20260812 06:20:22.299049 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: LogGCOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:22.299531 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:22.316844 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.017s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3648,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.317298 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling UndoDeltaBlockGCOp(0d5f2cfdef6c420b903dbfce5f078db7): 482 bytes on disk
I20260812 06:20:22.317710 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: UndoDeltaBlockGCOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.318213 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:22.332597 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.333168 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:22.547438 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.214s	user 0.153s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":695,"lbm_read_time_us":15790,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37372,"lbm_writes_lt_1ms":743,"mutex_wait_us":65,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5504,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:20:22.548022 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=18.063937
I20260812 06:20:22.603389 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.055s	user 0.042s	sys 0.011s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":23671,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:22.603950 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:22.627421 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.023s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.627882 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:22.642205 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5193,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.642668 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:22.809201 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.166s	user 0.144s	sys 0.022s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020632,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":73,"lbm_read_time_us":11362,"lbm_reads_lt_1ms":773,"lbm_write_time_us":33968,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":3500}
I20260812 06:20:22.810710 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:22.863173 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.052s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21986,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.863909 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:22.883617 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.018s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.884120 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:22.898475 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.898933 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:23.051528 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.152s	user 0.127s	sys 0.024s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918215,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":640,"lbm_read_time_us":10610,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30857,"lbm_writes_lt_1ms":643,"mutex_wait_us":366,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":3000}
I20260812 06:20:23.052018 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:23.094576 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.042s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17132,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.095072 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:23.106837 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.107275 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:23.264899 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.157s	user 0.109s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":367,"lbm_read_time_us":11189,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26143,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:20:23.265524 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:23.326683 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.061s	user 0.019s	sys 0.027s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":20622,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.327229 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:23.336997 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3519,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.337643 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:23.514832 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.177s	user 0.107s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":725,"lbm_read_time_us":12744,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29374,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:20:23.515347 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=14.095187
I20260812 06:20:23.571146 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.056s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20325,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.571705 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:23.586440 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5552,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.586917 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushMRSOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:23.621790 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushMRSOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.035s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1216,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1331,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:23.622505 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling LogGCOp(0d5f2cfdef6c420b903dbfce5f078db7): free 124257506 bytes of WAL
I20260812 06:20:23.622745 15741 log_reader.cc:385] T 0d5f2cfdef6c420b903dbfce5f078db7: removed 12 log segments from log reader
I20260812 06:20:23.622802 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000028 (ops 134-138)
I20260812 06:20:23.622844 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000029 (ops 139-143)
I20260812 06:20:23.622879 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000030 (ops 144-148)
I20260812 06:20:23.622910 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000031 (ops 149-152)
I20260812 06:20:23.622937 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000032 (ops 153-157)
I20260812 06:20:23.622964 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000033 (ops 158-162)
I20260812 06:20:23.622994 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000034 (ops 163-167)
I20260812 06:20:23.623026 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000035 (ops 168-172)
I20260812 06:20:23.623059 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000036 (ops 173-177)
I20260812 06:20:23.623080 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000037 (ops 178-182)
I20260812 06:20:23.623101 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000038 (ops 183-187)
I20260812 06:20:23.623122 15741 log.cc:1079] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: Deleting log segment in path: /tmp/dist-test-task6gczna/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614180562-15247-0/minicluster-data/ts-0-root/wals/0d5f2cfdef6c420b903dbfce5f078db7/wal-000000039 (ops 188-192)
I20260812 06:20:23.649139 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: LogGCOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:23.649540 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling UndoDeltaBlockGCOp(0d5f2cfdef6c420b903dbfce5f078db7): 473 bytes on disk
I20260812 06:20:23.650029 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: UndoDeltaBlockGCOp(0d5f2cfdef6c420b903dbfce5f078db7) 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:20:23.650676 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=3.181125
I20260812 06:20:23.664621 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:23.665019 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=2.188937
I20260812 06:20:23.673653 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: FlushDeltaMemStoresOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.008s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3265,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.674173 15841 maintenance_manager.cc:419] P e7fdf68178a34d70be1ebbd1ead52cfe: Scheduling MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7): perf score=1.000000
I20260812 06:20:23.750120 15247 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.532s	user 1.585s	sys 0.180s
I20260812 06:20:23.837718 15247 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.002s	sys 0.000s
I20260812 06:20:23.838268 15247 tablet_server.cc:179] TabletServer@127.14.227.193:0 shutting down...
I20260812 06:20:23.868111 15741 maintenance_manager.cc:643] P e7fdf68178a34d70be1ebbd1ead52cfe: MajorDeltaCompactionOp(0d5f2cfdef6c420b903dbfce5f078db7) complete. Timing: real 0.194s	user 0.137s	sys 0.055s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2325,"lbm_read_time_us":12610,"lbm_reads_lt_1ms":770,"lbm_write_time_us":29465,"lbm_writes_lt_1ms":743,"mutex_wait_us":2003,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:20:23.868673 15247 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:23.868945 15247 tablet_replica.cc:333] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe: stopping tablet replica
I20260812 06:20:23.869074 15247 raft_consensus.cc:2243] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:23.869292 15247 raft_consensus.cc:2272] T 0d5f2cfdef6c420b903dbfce5f078db7 P e7fdf68178a34d70be1ebbd1ead52cfe [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:23.873754 15247 tablet_server.cc:196] TabletServer@127.14.227.193:0 shutdown complete.
I20260812 06:20:23.922626 15247 master.cc:562] Master@127.14.227.254:37415 shutting down...
I20260812 06:20:23.925709 15247 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:23.925895 15247 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:23.925971 15247 tablet_replica.cc:333] T 00000000000000000000000000000000 P c8e29f18ebfb45388e0128866ddb707e: stopping tablet replica
I20260812 06:20:23.938047 15247 master.cc:584] Master@127.14.227.254:37415 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4962 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9818 ms total)

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