[==========] 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:09.414593 32147 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.100.254:39967
I20260812 06:20:09.415527 32147 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:09.416082 32147 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:09.422344 32158 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:09.422571 32147 server_base.cc:1061] running on GCE node
W20260812 06:20:09.422361 32155 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:09.422650 32153 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.423233 32147 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:09.423323 32147 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:09.423348 32147 hybrid_clock.cc:648] HybridClock initialized: now 1786515609423347 us; error 0 us; skew 500 ppm
I20260812 06:20:09.425102 32147 webserver.cc:533] Webserver started at http://127.31.100.254:42873/ using document root <none> and password file <none>
I20260812 06:20:09.425594 32147 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:09.425648 32147 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:09.425836 32147 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:09.427448 32147 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/master-0-root/instance:
uuid: "53ff5879ea6548d2af2153dd2a06e776"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-68xk"
I20260812 06:20:09.430863 32147 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:09.432888 32167 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:09.433905 32147 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:09.434043 32147 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/master-0-root
uuid: "53ff5879ea6548d2af2153dd2a06e776"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-68xk"
I20260812 06:20:09.434150 32147 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-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:09.446993 32147 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:09.447642 32147 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:09.447855 32147 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:09.456190 32147 rpc_server.cc:307] RPC server started. Bound to: 127.31.100.254:39967
I20260812 06:20:09.456212 32253 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.100.254:39967 every 8 connection(s)
I20260812 06:20:09.458702 32254 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:09.464721 32254 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776: Bootstrap starting.
I20260812 06:20:09.467403 32254 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:09.468406 32254 log.cc:826] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:09.470523 32254 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776: No bootstrap required, opened a new log
I20260812 06:20:09.473553 32254 raft_consensus.cc:359] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53ff5879ea6548d2af2153dd2a06e776" member_type: VOTER }
I20260812 06:20:09.473730 32254 raft_consensus.cc:385] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:09.473810 32254 raft_consensus.cc:740] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 53ff5879ea6548d2af2153dd2a06e776, State: Initialized, Role: FOLLOWER
I20260812 06:20:09.474571 32254 consensus_queue.cc:260] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [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: "53ff5879ea6548d2af2153dd2a06e776" member_type: VOTER }
I20260812 06:20:09.474732 32254 raft_consensus.cc:399] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:09.474872 32254 raft_consensus.cc:493] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:09.475030 32254 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:09.475909 32254 raft_consensus.cc:515] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53ff5879ea6548d2af2153dd2a06e776" member_type: VOTER }
I20260812 06:20:09.476398 32254 leader_election.cc:304] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [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: 53ff5879ea6548d2af2153dd2a06e776; no voters: 
I20260812 06:20:09.476747 32254 leader_election.cc:290] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:09.476898 32257 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:09.477165 32257 raft_consensus.cc:697] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 1 LEADER]: Becoming Leader. State: Replica: 53ff5879ea6548d2af2153dd2a06e776, State: Running, Role: LEADER
I20260812 06:20:09.477640 32257 consensus_queue.cc:237] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [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: "53ff5879ea6548d2af2153dd2a06e776" member_type: VOTER }
I20260812 06:20:09.477888 32254 sys_catalog.cc:565] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:09.479687 32258 sys_catalog.cc:455] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "53ff5879ea6548d2af2153dd2a06e776" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53ff5879ea6548d2af2153dd2a06e776" member_type: VOTER } }
I20260812 06:20:09.479820 32258 sys_catalog.cc:458] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:09.479773 32259 sys_catalog.cc:455] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 53ff5879ea6548d2af2153dd2a06e776. Latest consensus state: current_term: 1 leader_uuid: "53ff5879ea6548d2af2153dd2a06e776" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53ff5879ea6548d2af2153dd2a06e776" member_type: VOTER } }
I20260812 06:20:09.479872 32259 sys_catalog.cc:458] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:09.480260 32271 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:09.482947 32271 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:09.483258 32147 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:09.487941 32271 catalog_manager.cc:1383] Generated new cluster ID: dc94d15b6c0841a1bcc34ed3d6e9d7ff
I20260812 06:20:09.488021 32271 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:09.497786 32271 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:09.498690 32271 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:09.504305 32271 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776: Generated new TSK 0
I20260812 06:20:09.504902 32271 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:09.516049 32147 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:09.519198 32283 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:09.519284 32284 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:09.519336 32147 server_base.cc:1061] running on GCE node
W20260812 06:20:09.519308 32287 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:09.519675 32147 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:09.519735 32147 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:09.519759 32147 hybrid_clock.cc:648] HybridClock initialized: now 1786515609519759 us; error 0 us; skew 500 ppm
I20260812 06:20:09.520742 32147 webserver.cc:533] Webserver started at http://127.31.100.193:44745/ using document root <none> and password file <none>
I20260812 06:20:09.520927 32147 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:09.520984 32147 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:09.521063 32147 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:09.521500 32147 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/instance:
uuid: "dff25accd6a24777a6237c4d10c1b92a"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-68xk"
I20260812 06:20:09.523413 32147 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:09.524547 32293 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:09.524884 32147 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:09.524976 32147 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root
uuid: "dff25accd6a24777a6237c4d10c1b92a"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-68xk"
I20260812 06:20:09.525072 32147 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-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:09.531939 32147 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:09.532331 32147 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:09.532775 32147 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:09.533651 32147 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:09.533725 32147 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.533795 32147 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:09.533840 32147 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.540737 32147 rpc_server.cc:307] RPC server started. Bound to: 127.31.100.193:34317
I20260812 06:20:09.540782 32410 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.100.193:34317 every 8 connection(s)
I20260812 06:20:09.554955 32412 heartbeater.cc:344] Connected to a master server at 127.31.100.254:39967
I20260812 06:20:09.555213 32412 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:09.555652 32412 heartbeater.cc:507] Master 127.31.100.254:39967 requested a full tablet report, sending...
I20260812 06:20:09.557194 32197 ts_manager.cc:194] Registered new tserver with Master: dff25accd6a24777a6237c4d10c1b92a (127.31.100.193:34317)
I20260812 06:20:09.557343 32147 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015976508s
I20260812 06:20:09.558732 32197 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42058
I20260812 06:20:09.567911 32197 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42066:
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:09.583376 32340 tablet_service.cc:1511] Processing CreateTablet for tablet cca741b264104ab3a839eb42f27ecad4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=c9c842cd7d664b2cbc152ed5a8aac0e9]), partition=
I20260812 06:20:09.583854 32340 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cca741b264104ab3a839eb42f27ecad4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:09.586732 32430 tablet_bootstrap.cc:492] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Bootstrap starting.
I20260812 06:20:09.587689 32430 tablet_bootstrap.cc:654] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:09.588847 32430 tablet_bootstrap.cc:492] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: No bootstrap required, opened a new log
I20260812 06:20:09.588972 32430 ts_tablet_manager.cc:1403] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:09.589504 32430 raft_consensus.cc:359] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dff25accd6a24777a6237c4d10c1b92a" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 34317 } }
I20260812 06:20:09.589651 32430 raft_consensus.cc:385] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:09.589735 32430 raft_consensus.cc:740] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dff25accd6a24777a6237c4d10c1b92a, State: Initialized, Role: FOLLOWER
I20260812 06:20:09.589896 32430 consensus_queue.cc:260] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [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: "dff25accd6a24777a6237c4d10c1b92a" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 34317 } }
I20260812 06:20:09.590006 32430 raft_consensus.cc:399] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:09.590052 32430 raft_consensus.cc:493] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:09.590152 32430 raft_consensus.cc:3060] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:09.591043 32430 raft_consensus.cc:515] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dff25accd6a24777a6237c4d10c1b92a" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 34317 } }
I20260812 06:20:09.591215 32430 leader_election.cc:304] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [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: dff25accd6a24777a6237c4d10c1b92a; no voters: 
I20260812 06:20:09.591459 32430 leader_election.cc:290] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:09.591565 32433 raft_consensus.cc:2804] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:09.591771 32433 raft_consensus.cc:697] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 1 LEADER]: Becoming Leader. State: Replica: dff25accd6a24777a6237c4d10c1b92a, State: Running, Role: LEADER
I20260812 06:20:09.591845 32430 ts_tablet_manager.cc:1434] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:09.592069 32412 heartbeater.cc:499] Master 127.31.100.254:39967 was elected leader, sending a full tablet report...
I20260812 06:20:09.592430 32433 consensus_queue.cc:237] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [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: "dff25accd6a24777a6237c4d10c1b92a" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 34317 } }
I20260812 06:20:09.595419 32197 catalog_manager.cc:5719] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a reported cstate change: term changed from 0 to 1, leader changed from <none> to dff25accd6a24777a6237c4d10c1b92a (127.31.100.193). New cstate: current_term: 1 leader_uuid: "dff25accd6a24777a6237c4d10c1b92a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dff25accd6a24777a6237c4d10c1b92a" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 34317 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:09.666528 32147 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.024s	sys 0.004s
I20260812 06:20:09.792001 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushMRSOp(cca741b264104ab3a839eb42f27ecad4): perf score=15.086190
I20260812 06:20:09.944715 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushMRSOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.152s	user 0.124s	sys 0.025s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":212,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":843,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38388,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":149,"threads_started":1,"update_count":1500}
I20260812 06:20:09.946456 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling LogGCOp(cca741b264104ab3a839eb42f27ecad4): free 11976772 bytes of WAL
I20260812 06:20:09.947454 32300 log_reader.cc:385] T cca741b264104ab3a839eb42f27ecad4: removed 1 log segments from log reader
I20260812 06:20:09.947638 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000001 (ops 1-6)
I20260812 06:20:09.951421 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: LogGCOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:09.951871 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:09.980635 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.029s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.981185 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling UndoDeltaBlockGCOp(cca741b264104ab3a839eb42f27ecad4): 12308962 bytes on disk
I20260812 06:20:09.981837 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: UndoDeltaBlockGCOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.982307 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:09.998729 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.016s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6320,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.999387 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:10.205518 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.206s	user 0.135s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733843,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":627,"lbm_read_time_us":16804,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30665,"lbm_writes_lt_1ms":543,"mutex_wait_us":131,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":335,"threads_started":5,"update_count":2500}
I20260812 06:20:10.206112 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=14.095187
I20260812 06:20:10.260509 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.054s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21268,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.261008 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:10.272028 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4063,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.272511 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:10.420634 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.148s	user 0.124s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":10918,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27703,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2500}
I20260812 06:20:10.421229 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=11.118625
I20260812 06:20:10.460943 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.040s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17272,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:10.461566 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:10.474517 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.474942 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:10.603303 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.128s	user 0.090s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":453,"lbm_read_time_us":7268,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24757,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.604034 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:10.651556 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.047s	user 0.018s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20457,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.652172 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:10.669962 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6849,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.670626 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:10.810250 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.139s	user 0.102s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":898,"lbm_read_time_us":10575,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26319,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:10.811051 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=11.118625
I20260812 06:20:10.857901 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.047s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15856,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:10.858641 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:10.869786 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.870620 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:11.031283 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.160s	user 0.110s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":12056,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26118,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2000}
I20260812 06:20:11.031869 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:11.075485 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.043s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19349,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.076047 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:11.088728 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.089294 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:11.224462 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.135s	user 0.117s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":10089,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25393,"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:11.225020 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:11.267820 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.043s	user 0.029s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17464,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.268407 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:11.278962 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.279397 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushMRSOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:11.312491 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushMRSOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.033s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":92,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1385,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2147,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:11.313295 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling LogGCOp(cca741b264104ab3a839eb42f27ecad4): free 121006369 bytes of WAL
I20260812 06:20:11.313524 32300 log_reader.cc:385] T cca741b264104ab3a839eb42f27ecad4: removed 12 log segments from log reader
I20260812 06:20:11.313588 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000002 (ops 7-11)
I20260812 06:20:11.313642 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000003 (ops 12-16)
I20260812 06:20:11.313704 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000004 (ops 17-21)
I20260812 06:20:11.313747 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000005 (ops 22-26)
I20260812 06:20:11.313787 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000006 (ops 27-30)
I20260812 06:20:11.313823 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000007 (ops 31-35)
I20260812 06:20:11.313860 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000008 (ops 36-40)
I20260812 06:20:11.313897 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000009 (ops 41-45)
I20260812 06:20:11.313933 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000010 (ops 46-50)
I20260812 06:20:11.313969 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000011 (ops 51-55)
I20260812 06:20:11.314006 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000012 (ops 56-60)
I20260812 06:20:11.314042 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000013 (ops 61-65)
I20260812 06:20:11.341593 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: LogGCOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:11.342073 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling UndoDeltaBlockGCOp(cca741b264104ab3a839eb42f27ecad4): 473 bytes on disk
I20260812 06:20:11.342713 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: UndoDeltaBlockGCOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.343163 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:11.357892 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.015s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.358325 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling LogGCOp(cca741b264104ab3a839eb42f27ecad4): free 12017983 bytes of WAL
I20260812 06:20:11.358628 32300 log_reader.cc:385] T cca741b264104ab3a839eb42f27ecad4: removed 1 log segments from log reader
I20260812 06:20:11.358704 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000014 (ops 66-70)
I20260812 06:20:11.361882 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: LogGCOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:11.362228 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:11.372933 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.373562 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:11.554725 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.181s	user 0.150s	sys 0.022s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836372,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":504,"lbm_read_time_us":12801,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35765,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:20:11.555354 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=14.095187
I20260812 06:20:11.609701 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.054s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22901,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.610258 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:11.621443 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.622071 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:11.780956 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.159s	user 0.123s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":448,"lbm_read_time_us":9924,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32334,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:20:11.781594 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=11.118625
I20260812 06:20:11.820446 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.039s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16450,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:11.821430 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:11.851410 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.030s	user 0.015s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6388,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":450}
I20260812 06:20:11.851897 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:11.863754 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.012s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.864245 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:12.071383 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.207s	user 0.127s	sys 0.071s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1162,"lbm_read_time_us":14647,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35100,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:12.071985 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=14.095187
I20260812 06:20:12.124408 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.052s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21804,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.124898 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:12.282053 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.157s	user 0.090s	sys 0.065s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":157,"lbm_read_time_us":10657,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27144,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.282773 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=11.118625
I20260812 06:20:12.317556 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.035s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15499,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.318137 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:12.342085 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.024s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4977,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.342623 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:12.353171 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.353627 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:12.558290 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.204s	user 0.124s	sys 0.062s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":392,"lbm_read_time_us":11823,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31841,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:20:12.558923 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=14.095187
I20260812 06:20:12.611706 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.053s	user 0.036s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20254,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.612179 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:12.623526 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.624011 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:12.787334 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.163s	user 0.116s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":681,"lbm_read_time_us":9946,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32160,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:12.792685 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=11.118625
I20260812 06:20:12.838085 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.044s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19151,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.838768 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:12.854758 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5632,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.855227 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushMRSOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:12.894194 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushMRSOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.039s	user 0.033s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1323,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1892,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:12.895219 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling LogGCOp(cca741b264104ab3a839eb42f27ecad4): free 121006436 bytes of WAL
I20260812 06:20:12.895499 32300 log_reader.cc:385] T cca741b264104ab3a839eb42f27ecad4: removed 12 log segments from log reader
I20260812 06:20:12.895583 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000015 (ops 71-75)
I20260812 06:20:12.895665 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000016 (ops 76-80)
I20260812 06:20:12.895728 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000017 (ops 81-84)
I20260812 06:20:12.895787 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000018 (ops 85-89)
I20260812 06:20:12.895851 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000019 (ops 90-94)
I20260812 06:20:12.895915 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000020 (ops 95-99)
I20260812 06:20:12.895974 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000021 (ops 100-104)
I20260812 06:20:12.896032 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000022 (ops 105-109)
I20260812 06:20:12.896095 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000023 (ops 110-114)
I20260812 06:20:12.896173 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000024 (ops 115-119)
I20260812 06:20:12.896234 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000025 (ops 120-124)
I20260812 06:20:12.896294 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000026 (ops 125-129)
I20260812 06:20:12.927739 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: LogGCOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:12.928289 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=4.173312
I20260812 06:20:12.947603 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":6071825,"delete_count":0,"lbm_write_time_us":8106,"lbm_writes_lt_1ms":151,"reinsert_count":0,"update_count":740}
I20260812 06:20:12.948107 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:12.954577 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.006s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2133453,"delete_count":0,"lbm_write_time_us":2113,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:20:12.955008 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling UndoDeltaBlockGCOp(cca741b264104ab3a839eb42f27ecad4): 482 bytes on disk
I20260812 06:20:12.955533 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: UndoDeltaBlockGCOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.956132 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:13.181751 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.225s	user 0.146s	sys 0.075s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836319,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":547,"lbm_read_time_us":15975,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40960,"lbm_writes_lt_1ms":643,"mutex_wait_us":371,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7168,"thread_start_us":104,"threads_started":1,"update_count":3000}
I20260812 06:20:13.182559 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=11.118625
I20260812 06:20:13.222483 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.040s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17811,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.223042 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:13.235613 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4872,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.236045 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:13.376518 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.140s	user 0.112s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631305,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":174,"lbm_read_time_us":8529,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28186,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:20:13.377259 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=7.149875
I20260812 06:20:13.399891 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.022s	user 0.013s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9582,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:13.400341 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:13.410528 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3734,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.411092 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:13.538532 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.127s	user 0.082s	sys 0.034s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":805,"lbm_read_time_us":8271,"lbm_reads_lt_1ms":372,"lbm_write_time_us":21519,"lbm_writes_lt_1ms":343,"mutex_wait_us":347,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:20:13.539243 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:13.573365 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.034s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14719,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.573830 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:13.701370 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.127s	user 0.085s	sys 0.037s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1097,"lbm_read_time_us":10008,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20378,"lbm_writes_lt_1ms":343,"mutex_wait_us":265,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.702095 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:13.748579 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.046s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15351,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.749119 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:13.760548 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.761222 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:13.885979 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.125s	user 0.095s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":932,"lbm_read_time_us":8993,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24590,"lbm_writes_lt_1ms":443,"mutex_wait_us":284,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:13.886605 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:13.929662 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.043s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20707,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.930244 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:13.943596 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.944321 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:14.067126 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.123s	user 0.078s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":360,"lbm_read_time_us":8689,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24432,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:14.067925 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:14.123890 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.056s	user 0.026s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20418,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.124432 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:14.135033 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.135567 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:14.280711 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.145s	user 0.096s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":11654,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22805,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:20:14.282867 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:14.321943 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.039s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16718,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.322508 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:14.333174 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4278,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.333873 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:14.473299 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.139s	user 0.111s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":8323,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27025,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22912,"update_count":2000}
I20260812 06:20:14.473942 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:14.521729 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.048s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16454,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.522540 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:14.533816 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.534735 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushMRSOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:14.565448 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushMRSOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1448,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1572,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:14.566263 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling LogGCOp(cca741b264104ab3a839eb42f27ecad4): free 132571598 bytes of WAL
I20260812 06:20:14.566538 32300 log_reader.cc:385] T cca741b264104ab3a839eb42f27ecad4: removed 13 log segments from log reader
I20260812 06:20:14.566609 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000027 (ops 130-134)
I20260812 06:20:14.566668 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000028 (ops 135-139)
I20260812 06:20:14.566723 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000029 (ops 140-144)
I20260812 06:20:14.566763 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000030 (ops 145-149)
I20260812 06:20:14.566802 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000031 (ops 150-154)
I20260812 06:20:14.566840 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000032 (ops 155-158)
I20260812 06:20:14.566877 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000033 (ops 159-163)
I20260812 06:20:14.566915 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000034 (ops 164-168)
I20260812 06:20:14.566951 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000035 (ops 169-173)
I20260812 06:20:14.566988 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000036 (ops 174-178)
I20260812 06:20:14.567024 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000037 (ops 179-182)
I20260812 06:20:14.567060 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000038 (ops 183-187)
I20260812 06:20:14.567097 32300 log.cc:1079] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/cca741b264104ab3a839eb42f27ecad4/wal-000000039 (ops 188-192)
I20260812 06:20:14.599025 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: LogGCOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:20:14.599588 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=3.181125
I20260812 06:20:14.617249 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.017s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4841095,"delete_count":0,"lbm_write_time_us":7407,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:20:14.617688 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling UndoDeltaBlockGCOp(cca741b264104ab3a839eb42f27ecad4): 483 bytes on disk
I20260812 06:20:14.618080 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: UndoDeltaBlockGCOp(cca741b264104ab3a839eb42f27ecad4) 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:14.618815 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=2.188937
I20260812 06:20:14.628697 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.010s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":3358,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:20:14.629135 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4): perf score=1.000000
I20260812 06:20:14.745684 32147 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.079s	user 1.865s	sys 0.135s
I20260812 06:20:14.781476 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: MajorDeltaCompactionOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.152s	user 0.118s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836354,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":11114,"lbm_reads_lt_1ms":670,"lbm_write_time_us":32409,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:20:14.782109 32414 maintenance_manager.cc:419] P dff25accd6a24777a6237c4d10c1b92a: Scheduling FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4): perf score=10.126437
I20260812 06:20:14.819545 32147 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.073s	user 0.003s	sys 0.000s
I20260812 06:20:14.820232 32147 tablet_server.cc:179] TabletServer@127.31.100.193:0 shutting down...
I20260812 06:20:14.854532 32300 maintenance_manager.cc:643] P dff25accd6a24777a6237c4d10c1b92a: FlushDeltaMemStoresOp(cca741b264104ab3a839eb42f27ecad4) complete. Timing: real 0.072s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12405,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.855278 32147 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:14.855685 32147 tablet_replica.cc:333] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a: stopping tablet replica
I20260812 06:20:14.855934 32147 raft_consensus.cc:2243] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.856181 32147 raft_consensus.cc:2272] T cca741b264104ab3a839eb42f27ecad4 P dff25accd6a24777a6237c4d10c1b92a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.872225 32147 tablet_server.cc:196] TabletServer@127.31.100.193:0 shutdown complete.
I20260812 06:20:14.877223 32147 master.cc:562] Master@127.31.100.254:39967 shutting down...
I20260812 06:20:14.881417 32147 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.881613 32147 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.881726 32147 tablet_replica.cc:333] T 00000000000000000000000000000000 P 53ff5879ea6548d2af2153dd2a06e776: stopping tablet replica
I20260812 06:20:14.894133 32147 master.cc:584] Master@127.31.100.254:39967 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5573 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:14.988312 32147 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.100.254:40303
I20260812 06:20:14.988751 32147 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.991065 32467 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:14.990989 32470 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:14.990980 32466 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.991091 32147 server_base.cc:1061] running on GCE node
I20260812 06:20:14.991438 32147 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.991478 32147 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.991493 32147 hybrid_clock.cc:648] HybridClock initialized: now 1786515614991494 us; error 0 us; skew 500 ppm
I20260812 06:20:14.992327 32147 webserver.cc:533] Webserver started at http://127.31.100.254:40661/ using document root <none> and password file <none>
I20260812 06:20:14.992470 32147 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.992512 32147 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.992571 32147 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.992934 32147 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/master-0-root/instance:
uuid: "6192cb384e7143d59d48e874b1d51a91"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-68xk"
I20260812 06:20:14.994575 32147 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:14.995496 32477 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.995761 32147 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:14.995857 32147 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/master-0-root
uuid: "6192cb384e7143d59d48e874b1d51a91"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-68xk"
I20260812 06:20:14.995947 32147 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-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:15.009964 32147 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:15.010569 32147 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:15.015224 32147 rpc_server.cc:307] RPC server started. Bound to: 127.31.100.254:40303
I20260812 06:20:15.016829 32564 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.100.254:40303 every 8 connection(s)
I20260812 06:20:15.019270 32568 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:15.033638 32568 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91: Bootstrap starting.
I20260812 06:20:15.034636 32568 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:15.035818 32568 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91: No bootstrap required, opened a new log
I20260812 06:20:15.036291 32568 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6192cb384e7143d59d48e874b1d51a91" member_type: VOTER }
I20260812 06:20:15.036414 32568 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:15.036489 32568 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6192cb384e7143d59d48e874b1d51a91, State: Initialized, Role: FOLLOWER
I20260812 06:20:15.036710 32568 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [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: "6192cb384e7143d59d48e874b1d51a91" member_type: VOTER }
I20260812 06:20:15.036814 32568 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:15.036862 32568 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:15.036926 32568 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:15.037657 32568 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6192cb384e7143d59d48e874b1d51a91" member_type: VOTER }
I20260812 06:20:15.037828 32568 leader_election.cc:304] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [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: 6192cb384e7143d59d48e874b1d51a91; no voters: 
I20260812 06:20:15.038053 32568 leader_election.cc:290] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:15.038250 32574 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:15.038522 32574 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 1 LEADER]: Becoming Leader. State: Replica: 6192cb384e7143d59d48e874b1d51a91, State: Running, Role: LEADER
I20260812 06:20:15.038697 32568 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:15.038727 32574 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [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: "6192cb384e7143d59d48e874b1d51a91" member_type: VOTER }
I20260812 06:20:15.039149 32575 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6192cb384e7143d59d48e874b1d51a91" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6192cb384e7143d59d48e874b1d51a91" member_type: VOTER } }
I20260812 06:20:15.039261 32575 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:15.039163 32576 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6192cb384e7143d59d48e874b1d51a91. Latest consensus state: current_term: 1 leader_uuid: "6192cb384e7143d59d48e874b1d51a91" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6192cb384e7143d59d48e874b1d51a91" member_type: VOTER } }
I20260812 06:20:15.039397 32576 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:15.040786 32147 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:15.041281 32600 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:15.041370 32600 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:15.041469 32582 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:15.042266 32582 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:15.044269 32582 catalog_manager.cc:1383] Generated new cluster ID: 1d42b12c6983456087ff29d3e967c8d1
I20260812 06:20:15.044334 32582 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:15.054361 32582 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:15.055001 32582 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:15.063336 32582 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91: Generated new TSK 0
I20260812 06:20:15.063699 32582 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:15.073189 32147 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:15.075203 32602 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:15.075317 32607 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:15.075208 32603 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:15.075363 32147 server_base.cc:1061] running on GCE node
I20260812 06:20:15.075611 32147 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:15.075665 32147 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:15.075682 32147 hybrid_clock.cc:648] HybridClock initialized: now 1786515615075682 us; error 0 us; skew 500 ppm
I20260812 06:20:15.076646 32147 webserver.cc:533] Webserver started at http://127.31.100.193:46621/ using document root <none> and password file <none>
I20260812 06:20:15.076831 32147 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:15.076893 32147 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:15.076998 32147 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:15.077418 32147 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/instance:
uuid: "ad61119fd9ce4a089a82e597215e11da"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-68xk"
I20260812 06:20:15.079087 32147 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:15.080084 32616 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:15.080405 32147 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:15.080499 32147 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root
uuid: "ad61119fd9ce4a089a82e597215e11da"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-68xk"
I20260812 06:20:15.080596 32147 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-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:15.086387 32147 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:15.086788 32147 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:15.087088 32147 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:15.087563 32147 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:15.087626 32147 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.087683 32147 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:15.087716 32147 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.092350 32147 rpc_server.cc:307] RPC server started. Bound to: 127.31.100.193:35479
I20260812 06:20:15.092386 32718 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.100.193:35479 every 8 connection(s)
I20260812 06:20:15.119189 32720 heartbeater.cc:344] Connected to a master server at 127.31.100.254:40303
I20260812 06:20:15.119338 32720 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:15.119616 32720 heartbeater.cc:507] Master 127.31.100.254:40303 requested a full tablet report, sending...
I20260812 06:20:15.120428 32501 ts_manager.cc:194] Registered new tserver with Master: ad61119fd9ce4a089a82e597215e11da (127.31.100.193:35479)
I20260812 06:20:15.121239 32147 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.028443021s
I20260812 06:20:15.121256 32501 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56262
I20260812 06:20:15.129098 32501 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56278:
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:15.138921 32661 tablet_service.cc:1511] Processing CreateTablet for tablet bca5a20537114ab99f667cc3f45f0447 (DEFAULT_TABLE table=heavy-update-compaction-test [id=918dcdeb500b4db29c63b848591ce7b2]), partition=
I20260812 06:20:15.139302 32661 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bca5a20537114ab99f667cc3f45f0447. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:15.141635 32745 tablet_bootstrap.cc:492] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Bootstrap starting.
I20260812 06:20:15.142619 32745 tablet_bootstrap.cc:654] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:15.144034 32745 tablet_bootstrap.cc:492] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: No bootstrap required, opened a new log
I20260812 06:20:15.144135 32745 ts_tablet_manager.cc:1403] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:20:15.144565 32745 raft_consensus.cc:359] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ad61119fd9ce4a089a82e597215e11da" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 35479 } }
I20260812 06:20:15.144657 32745 raft_consensus.cc:385] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:15.144716 32745 raft_consensus.cc:740] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ad61119fd9ce4a089a82e597215e11da, State: Initialized, Role: FOLLOWER
I20260812 06:20:15.144899 32745 consensus_queue.cc:260] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [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: "ad61119fd9ce4a089a82e597215e11da" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 35479 } }
I20260812 06:20:15.144995 32745 raft_consensus.cc:399] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:15.145092 32745 raft_consensus.cc:493] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:15.145144 32745 raft_consensus.cc:3060] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:15.145896 32745 raft_consensus.cc:515] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ad61119fd9ce4a089a82e597215e11da" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 35479 } }
I20260812 06:20:15.146078 32745 leader_election.cc:304] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [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: ad61119fd9ce4a089a82e597215e11da; no voters: 
I20260812 06:20:15.146335 32745 leader_election.cc:290] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:15.146517 32751 raft_consensus.cc:2804] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:15.146764 32745 ts_tablet_manager.cc:1434] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:15.146800 32720 heartbeater.cc:499] Master 127.31.100.254:40303 was elected leader, sending a full tablet report...
I20260812 06:20:15.146818 32751 raft_consensus.cc:697] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 1 LEADER]: Becoming Leader. State: Replica: ad61119fd9ce4a089a82e597215e11da, State: Running, Role: LEADER
I20260812 06:20:15.146988 32751 consensus_queue.cc:237] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [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: "ad61119fd9ce4a089a82e597215e11da" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 35479 } }
I20260812 06:20:15.148439 32501 catalog_manager.cc:5719] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da reported cstate change: term changed from 0 to 1, leader changed from <none> to ad61119fd9ce4a089a82e597215e11da (127.31.100.193). New cstate: current_term: 1 leader_uuid: "ad61119fd9ce4a089a82e597215e11da" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ad61119fd9ce4a089a82e597215e11da" member_type: VOTER last_known_addr { host: "127.31.100.193" port: 35479 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:15.212199 32147 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.021s	sys 0.004s
I20260812 06:20:15.343271 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushMRSOp(bca5a20537114ab99f667cc3f45f0447): perf score=15.086190
I20260812 06:20:15.482172 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushMRSOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.139s	user 0.102s	sys 0.032s Metrics: {"bytes_written":11897250,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":829,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37007,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:20:15.482815 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling LogGCOp(bca5a20537114ab99f667cc3f45f0447): free 20743880 bytes of WAL
I20260812 06:20:15.483070 32625 log_reader.cc:385] T bca5a20537114ab99f667cc3f45f0447: removed 2 log segments from log reader
I20260812 06:20:15.483206 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000001 (ops 1-6)
I20260812 06:20:15.483294 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000002 (ops 7-11)
I20260812 06:20:15.487998 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: LogGCOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:15.488334 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling UndoDeltaBlockGCOp(bca5a20537114ab99f667cc3f45f0447): 12719216 bytes on disk
I20260812 06:20:15.488749 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: UndoDeltaBlockGCOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.489140 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:15.505574 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.506139 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:15.642536 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.136s	user 0.105s	sys 0.024s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1100,"lbm_read_time_us":9627,"lbm_reads_lt_1ms":450,"lbm_write_time_us":23482,"lbm_writes_lt_1ms":433,"mutex_wait_us":146,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":366,"threads_started":5,"update_count":1950}
I20260812 06:20:15.643181 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:15.690973 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.048s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21616,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.691424 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:15.704351 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.704828 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:15.864409 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.159s	user 0.107s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":8734,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33340,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:20:15.865130 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=11.118625
I20260812 06:20:15.910871 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.046s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19727,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:15.911424 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:15.924546 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.013s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4310,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:15.925205 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:16.091853 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.166s	user 0.105s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":10985,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27997,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:20:16.092471 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:16.140655 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.048s	user 0.013s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19656,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.141170 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:16.162596 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.021s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.163053 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:16.352533 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.189s	user 0.112s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":12342,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30489,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:20:16.353219 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:16.405288 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.052s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19667,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.405793 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:16.420986 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.421608 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:16.596182 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.174s	user 0.109s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":468,"lbm_read_time_us":10673,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29043,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:20:16.596812 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=11.118625
I20260812 06:20:16.628183 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.031s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13237,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.628734 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:16.643616 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4947,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":450}
I20260812 06:20:16.644134 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:16.782866 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.139s	user 0.096s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":528,"lbm_read_time_us":9077,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25481,"lbm_writes_lt_1ms":443,"mutex_wait_us":132,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:20:16.783667 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=10.126437
I20260812 06:20:16.825457 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.042s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14190,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.826027 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:16.841176 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.841812 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushMRSOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:16.879438 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushMRSOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.037s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1349,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1967,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:16.880141 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling LogGCOp(bca5a20537114ab99f667cc3f45f0447): free 120553380 bytes of WAL
I20260812 06:20:16.880388 32625 log_reader.cc:385] T bca5a20537114ab99f667cc3f45f0447: removed 12 log segments from log reader
I20260812 06:20:16.880437 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000003 (ops 12-16)
I20260812 06:20:16.880486 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000004 (ops 17-20)
I20260812 06:20:16.880530 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000005 (ops 21-25)
I20260812 06:20:16.880560 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000006 (ops 26-30)
I20260812 06:20:16.880594 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000007 (ops 31-35)
I20260812 06:20:16.880635 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000008 (ops 36-40)
I20260812 06:20:16.880676 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000009 (ops 41-45)
I20260812 06:20:16.880714 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000010 (ops 46-50)
I20260812 06:20:16.880759 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000011 (ops 51-55)
I20260812 06:20:16.880796 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000012 (ops 56-60)
I20260812 06:20:16.880836 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000013 (ops 61-64)
I20260812 06:20:16.880874 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000014 (ops 65-69)
I20260812 06:20:16.909631 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: LogGCOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:16.910092 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling UndoDeltaBlockGCOp(bca5a20537114ab99f667cc3f45f0447): 470 bytes on disk
I20260812 06:20:16.910570 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: UndoDeltaBlockGCOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4,"spinlock_wait_cycles":5888}
I20260812 06:20:16.911026 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=5.165500
I20260812 06:20:16.927121 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":6728209,"delete_count":0,"lbm_write_time_us":6789,"lbm_writes_lt_1ms":167,"reinsert_count":0,"update_count":820}
I20260812 06:20:16.927517 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:16.934875 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.007s	user 0.003s	sys 0.003s Metrics: {"bytes_written":1477052,"delete_count":0,"lbm_write_time_us":2027,"lbm_writes_lt_1ms":39,"reinsert_count":0,"update_count":180}
I20260812 06:20:16.935429 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:17.122303 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.187s	user 0.136s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":491,"lbm_read_time_us":13473,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36770,"lbm_writes_lt_1ms":643,"mutex_wait_us":59,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:20:17.123769 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=15.087375
I20260812 06:20:17.163758 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.040s	user 0.024s	sys 0.014s Metrics: {"bytes_written":16779117,"delete_count":0,"lbm_write_time_us":17619,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2045}
I20260812 06:20:17.164552 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:17.192453 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.028s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":5569,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:17.192922 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:17.203296 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.203737 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:17.389343 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.185s	user 0.155s	sys 0.030s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877209,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":839,"lbm_read_time_us":13507,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38320,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:20:17.389947 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:17.443295 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.053s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23126,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.443936 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:17.459107 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.015s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.459640 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:17.616894 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.157s	user 0.108s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":342,"lbm_read_time_us":12131,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28307,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":77952,"update_count":2500}
I20260812 06:20:17.617655 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:17.687835 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.070s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26572,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.688350 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:17.699453 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.700150 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:17.880421 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.180s	user 0.131s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":14228,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29247,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:17.881135 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:17.934501 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.053s	user 0.044s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21833,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.935035 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:17.946030 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.946545 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:18.123070 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.176s	user 0.103s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":531,"lbm_read_time_us":13379,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30130,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:20:18.123682 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:18.186230 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.062s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21165,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.186791 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:18.197484 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.198045 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushMRSOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:18.240252 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushMRSOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.042s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1410,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1482,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:18.240984 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling LogGCOp(bca5a20537114ab99f667cc3f45f0447): free 115943191 bytes of WAL
I20260812 06:20:18.241209 32625 log_reader.cc:385] T bca5a20537114ab99f667cc3f45f0447: removed 11 log segments from log reader
I20260812 06:20:18.241256 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000015 (ops 70-74)
I20260812 06:20:18.241285 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000016 (ops 75-79)
I20260812 06:20:18.241348 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000017 (ops 80-84)
I20260812 06:20:18.241387 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000018 (ops 85-89)
I20260812 06:20:18.241432 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000019 (ops 90-94)
I20260812 06:20:18.241487 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000020 (ops 95-99)
I20260812 06:20:18.241549 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000021 (ops 100-104)
I20260812 06:20:18.241590 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000022 (ops 105-109)
I20260812 06:20:18.241628 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000023 (ops 110-114)
I20260812 06:20:18.241667 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000024 (ops 115-119)
I20260812 06:20:18.241710 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000025 (ops 120-124)
I20260812 06:20:18.268230 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: LogGCOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:18.269380 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling UndoDeltaBlockGCOp(bca5a20537114ab99f667cc3f45f0447): 447 bytes on disk
I20260812 06:20:18.269985 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: UndoDeltaBlockGCOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.270622 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=3.181125
I20260812 06:20:18.284595 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4456,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:18.285148 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:18.298972 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.014s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5258,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.299652 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:18.532685 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.233s	user 0.163s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":857,"lbm_read_time_us":15885,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41185,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10368,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:20:18.533783 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=15.087375
I20260812 06:20:18.579960 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.046s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20305,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:18.580458 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:18.600330 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.020s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.600783 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:18.611089 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.611524 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:18.815508 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.204s	user 0.140s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1390,"lbm_read_time_us":15084,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34942,"lbm_writes_lt_1ms":643,"mutex_wait_us":309,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:20:18.816979 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:18.875554 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.058s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24685,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.876179 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=3.181125
I20260812 06:20:18.889590 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4553930,"delete_count":0,"lbm_write_time_us":5586,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:20:18.890115 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:18.902812 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":4124,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:20:18.903316 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:19.094597 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.191s	user 0.151s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":271,"lbm_read_time_us":14294,"lbm_reads_lt_1ms":665,"lbm_write_time_us":42443,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":3000}
I20260812 06:20:19.095242 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:19.151264 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.056s	user 0.039s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25812,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.151819 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:19.169319 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.170370 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:19.338892 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.168s	user 0.118s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":11154,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32682,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:19.339653 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=14.095187
I20260812 06:20:19.386741 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.047s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21249,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.387213 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:19.546464 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.159s	user 0.123s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":977,"lbm_read_time_us":10063,"lbm_reads_lt_1ms":467,"lbm_write_time_us":29241,"lbm_writes_lt_1ms":443,"mutex_wait_us":296,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:20:19.547183 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=10.126437
I20260812 06:20:19.591274 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.044s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18864,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.591840 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:19.608709 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.610158 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushMRSOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:19.646914 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushMRSOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.037s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1488,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2404,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:19.647781 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling UndoDeltaBlockGCOp(bca5a20537114ab99f667cc3f45f0447): 448 bytes on disk
I20260812 06:20:19.648195 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: UndoDeltaBlockGCOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.648869 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=3.181125
I20260812 06:20:19.673858 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.025s	user 0.010s	sys 0.009s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7101,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:19.674589 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling LogGCOp(bca5a20537114ab99f667cc3f45f0447): free 121006626 bytes of WAL
I20260812 06:20:19.674877 32625 log_reader.cc:385] T bca5a20537114ab99f667cc3f45f0447: removed 12 log segments from log reader
I20260812 06:20:19.674952 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000026 (ops 125-129)
I20260812 06:20:19.675007 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000027 (ops 130-134)
I20260812 06:20:19.675045 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000028 (ops 135-139)
I20260812 06:20:19.675086 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000029 (ops 140-144)
I20260812 06:20:19.675127 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000030 (ops 145-148)
I20260812 06:20:19.675200 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000031 (ops 149-153)
I20260812 06:20:19.675243 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000032 (ops 154-158)
I20260812 06:20:19.675283 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000033 (ops 159-163)
I20260812 06:20:19.675323 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000034 (ops 164-168)
I20260812 06:20:19.675364 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000035 (ops 169-173)
I20260812 06:20:19.675405 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000036 (ops 174-178)
I20260812 06:20:19.675444 32625 log.cc:1079] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: Deleting log segment in path: /tmp/dist-test-tasktcLMV7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609404032-32147-0/minicluster-data/ts-0-root/wals/bca5a20537114ab99f667cc3f45f0447/wal-000000037 (ops 179-183)
I20260812 06:20:19.704044 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: LogGCOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:19.704618 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:19.720192 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.015s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.720640 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=2.188937
I20260812 06:20:19.730226 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3774,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.730665 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:19.976821 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.246s	user 0.161s	sys 0.083s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979856,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":272,"lbm_read_time_us":16857,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41635,"lbm_writes_lt_1ms":743,"mutex_wait_us":374,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":24704,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:20:19.978111 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=17.071750
I20260812 06:20:20.052561 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.074s	user 0.029s	sys 0.028s Metrics: {"bytes_written":19035454,"delete_count":0,"lbm_write_time_us":27430,"lbm_writes_lt_1ms":467,"reinsert_count":0,"update_count":2320}
I20260812 06:20:20.053048 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447): perf score=4.173312
I20260812 06:20:20.068272 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: FlushDeltaMemStoresOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":5579534,"delete_count":0,"lbm_write_time_us":6121,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:20:20.068812 32723 maintenance_manager.cc:419] P ad61119fd9ce4a089a82e597215e11da: Scheduling MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447): perf score=1.000000
I20260812 06:20:20.153970 32147 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.942s	user 1.822s	sys 0.183s
I20260812 06:20:20.217377 32147 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.063s	user 0.000s	sys 0.000s
I20260812 06:20:20.217883 32147 tablet_server.cc:179] TabletServer@127.31.100.193:0 shutting down...
I20260812 06:20:20.254037 32625 maintenance_manager.cc:643] P ad61119fd9ce4a089a82e597215e11da: MajorDeltaCompactionOp(bca5a20537114ab99f667cc3f45f0447) complete. Timing: real 0.185s	user 0.124s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877110,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":421,"lbm_read_time_us":17071,"lbm_reads_lt_1ms":668,"lbm_write_time_us":28701,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:20.254678 32147 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:20.255088 32147 tablet_replica.cc:333] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da: stopping tablet replica
I20260812 06:20:20.255249 32147 raft_consensus.cc:2243] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:20.266252 32147 raft_consensus.cc:2272] T bca5a20537114ab99f667cc3f45f0447 P ad61119fd9ce4a089a82e597215e11da [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:20.281844 32147 tablet_server.cc:196] TabletServer@127.31.100.193:0 shutdown complete.
I20260812 06:20:20.308418 32147 master.cc:562] Master@127.31.100.254:40303 shutting down...
I20260812 06:20:20.311990 32147 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:20.312172 32147 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:20.312225 32147 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6192cb384e7143d59d48e874b1d51a91: stopping tablet replica
I20260812 06:20:20.324579 32147 master.cc:584] Master@127.31.100.254:40303 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5430 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11004 ms total)

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