[==========] 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:16:54.407269 16040 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.170.62:39619
I20260812 06:16:54.408324 16040 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:16:54.408981 16040 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:54.415853 16046 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:16:54.415865 16049 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:16:54.415915 16040 server_base.cc:1061] running on GCE node
W20260812 06:16:54.416115 16052 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:16:54.416591 16040 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:54.416683 16040 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:16:54.416708 16040 hybrid_clock.cc:648] HybridClock initialized: now 1786515414416707 us; error 0 us; skew 500 ppm
I20260812 06:16:54.418521 16040 webserver.cc:533] Webserver started at http://127.15.170.62:44483/ using document root <none> and password file <none>
I20260812 06:16:54.419025 16040 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:54.419082 16040 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:54.419267 16040 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:54.420928 16040 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/master-0-root/instance:
uuid: "dbe273a3928a4ac5a2defd389343a05a"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-g170"
I20260812 06:16:54.424319 16040 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:54.426394 16060 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:16:54.427415 16040 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:16:54.427551 16040 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/master-0-root
uuid: "dbe273a3928a4ac5a2defd389343a05a"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-g170"
I20260812 06:16:54.427654 16040 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-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:16:54.442905 16040 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:54.443552 16040 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:16:54.443745 16040 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:54.451627 16153 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.170.62:39619 every 8 connection(s)
I20260812 06:16:54.451627 16040 rpc_server.cc:307] RPC server started. Bound to: 127.15.170.62:39619
I20260812 06:16:54.454115 16154 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:16:54.459725 16154 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a: Bootstrap starting.
I20260812 06:16:54.462136 16154 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:54.462998 16154 log.cc:826] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:54.464664 16154 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a: No bootstrap required, opened a new log
I20260812 06:16:54.467455 16154 raft_consensus.cc:359] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbe273a3928a4ac5a2defd389343a05a" member_type: VOTER }
I20260812 06:16:54.467618 16154 raft_consensus.cc:385] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:54.467661 16154 raft_consensus.cc:740] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dbe273a3928a4ac5a2defd389343a05a, State: Initialized, Role: FOLLOWER
I20260812 06:16:54.468256 16154 consensus_queue.cc:260] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [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: "dbe273a3928a4ac5a2defd389343a05a" member_type: VOTER }
I20260812 06:16:54.468401 16154 raft_consensus.cc:399] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:54.468442 16154 raft_consensus.cc:493] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:54.468525 16154 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:54.469328 16154 raft_consensus.cc:515] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbe273a3928a4ac5a2defd389343a05a" member_type: VOTER }
I20260812 06:16:54.469718 16154 leader_election.cc:304] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [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: dbe273a3928a4ac5a2defd389343a05a; no voters: 
I20260812 06:16:54.469990 16154 leader_election.cc:290] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:54.470222 16159 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:54.470499 16159 raft_consensus.cc:697] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 1 LEADER]: Becoming Leader. State: Replica: dbe273a3928a4ac5a2defd389343a05a, State: Running, Role: LEADER
I20260812 06:16:54.470964 16159 consensus_queue.cc:237] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [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: "dbe273a3928a4ac5a2defd389343a05a" member_type: VOTER }
I20260812 06:16:54.471040 16154 sys_catalog.cc:565] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:54.472992 16165 sys_catalog.cc:455] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [sys.catalog]: SysCatalogTable state changed. Reason: New leader dbe273a3928a4ac5a2defd389343a05a. Latest consensus state: current_term: 1 leader_uuid: "dbe273a3928a4ac5a2defd389343a05a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbe273a3928a4ac5a2defd389343a05a" member_type: VOTER } }
I20260812 06:16:54.473004 16161 sys_catalog.cc:455] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dbe273a3928a4ac5a2defd389343a05a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbe273a3928a4ac5a2defd389343a05a" member_type: VOTER } }
I20260812 06:16:54.473140 16165 sys_catalog.cc:458] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:54.473143 16161 sys_catalog.cc:458] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:54.473625 16040 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:54.475553 16190 catalog_manager.cc:1594] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:54.475657 16190 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:54.475749 16184 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:54.476504 16184 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:54.481568 16184 catalog_manager.cc:1383] Generated new cluster ID: 4fa4b697fddd458f85fec04ae8f35907
I20260812 06:16:54.481637 16184 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:54.489730 16184 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:54.490942 16184 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:54.497402 16184 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a: Generated new TSK 0
I20260812 06:16:54.498036 16184 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:54.506202 16040 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:54.509078 16197 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:16:54.509020 16200 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:16:54.509025 16202 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:16:54.509517 16040 server_base.cc:1061] running on GCE node
I20260812 06:16:54.509714 16040 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:54.509774 16040 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:16:54.509814 16040 hybrid_clock.cc:648] HybridClock initialized: now 1786515414509814 us; error 0 us; skew 500 ppm
I20260812 06:16:54.510848 16040 webserver.cc:533] Webserver started at http://127.15.170.1:33323/ using document root <none> and password file <none>
I20260812 06:16:54.511044 16040 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:54.511119 16040 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:54.511204 16040 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:54.511618 16040 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/instance:
uuid: "a16c6e288cd644c6b024cefad8f9da91"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-g170"
I20260812 06:16:54.513252 16040 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:54.514366 16212 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:16:54.514678 16040 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:54.514815 16040 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root
uuid: "a16c6e288cd644c6b024cefad8f9da91"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-g170"
I20260812 06:16:54.514918 16040 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-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:16:54.535458 16040 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:54.535985 16040 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:54.536551 16040 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:54.537524 16040 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:54.537604 16040 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:54.537679 16040 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:54.537741 16040 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:54.544941 16040 rpc_server.cc:307] RPC server started. Bound to: 127.15.170.1:34895
I20260812 06:16:54.545013 16335 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.170.1:34895 every 8 connection(s)
I20260812 06:16:54.557132 16336 heartbeater.cc:344] Connected to a master server at 127.15.170.62:39619
I20260812 06:16:54.557430 16336 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:54.557950 16336 heartbeater.cc:507] Master 127.15.170.62:39619 requested a full tablet report, sending...
I20260812 06:16:54.559644 16088 ts_manager.cc:194] Registered new tserver with Master: a16c6e288cd644c6b024cefad8f9da91 (127.15.170.1:34895)
I20260812 06:16:54.560438 16040 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014732344s
I20260812 06:16:54.561299 16088 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54384
I20260812 06:16:54.571710 16088 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54394:
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:16:54.587759 16267 tablet_service.cc:1511] Processing CreateTablet for tablet 16e2f245008e4c42a8e1a88aa81c0b71 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6c865656c6b2469ea2c179ea33b24a88]), partition=
I20260812 06:16:54.588232 16267 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 16e2f245008e4c42a8e1a88aa81c0b71. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:54.590621 16355 tablet_bootstrap.cc:492] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Bootstrap starting.
I20260812 06:16:54.591761 16355 tablet_bootstrap.cc:654] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:54.593043 16355 tablet_bootstrap.cc:492] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: No bootstrap required, opened a new log
I20260812 06:16:54.593142 16355 ts_tablet_manager.cc:1403] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:54.593607 16355 raft_consensus.cc:359] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a16c6e288cd644c6b024cefad8f9da91" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 34895 } }
I20260812 06:16:54.593724 16355 raft_consensus.cc:385] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:54.593756 16355 raft_consensus.cc:740] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a16c6e288cd644c6b024cefad8f9da91, State: Initialized, Role: FOLLOWER
I20260812 06:16:54.593878 16355 consensus_queue.cc:260] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [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: "a16c6e288cd644c6b024cefad8f9da91" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 34895 } }
I20260812 06:16:54.593964 16355 raft_consensus.cc:399] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:54.593998 16355 raft_consensus.cc:493] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:54.594044 16355 raft_consensus.cc:3060] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:54.594986 16355 raft_consensus.cc:515] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a16c6e288cd644c6b024cefad8f9da91" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 34895 } }
I20260812 06:16:54.595135 16355 leader_election.cc:304] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [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: a16c6e288cd644c6b024cefad8f9da91; no voters: 
I20260812 06:16:54.595345 16355 leader_election.cc:290] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:54.595523 16358 raft_consensus.cc:2804] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:54.595652 16355 ts_tablet_manager.cc:1434] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:54.595814 16358 raft_consensus.cc:697] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 1 LEADER]: Becoming Leader. State: Replica: a16c6e288cd644c6b024cefad8f9da91, State: Running, Role: LEADER
I20260812 06:16:54.595992 16336 heartbeater.cc:499] Master 127.15.170.62:39619 was elected leader, sending a full tablet report...
I20260812 06:16:54.596040 16358 consensus_queue.cc:237] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [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: "a16c6e288cd644c6b024cefad8f9da91" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 34895 } }
I20260812 06:16:54.598667 16088 catalog_manager.cc:5719] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 reported cstate change: term changed from 0 to 1, leader changed from <none> to a16c6e288cd644c6b024cefad8f9da91 (127.15.170.1). New cstate: current_term: 1 leader_uuid: "a16c6e288cd644c6b024cefad8f9da91" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a16c6e288cd644c6b024cefad8f9da91" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 34895 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:54.670573 16040 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.019s	sys 0.012s
I20260812 06:16:54.796366 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushMRSOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=15.086190
I20260812 06:16:54.966390 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushMRSOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.169s	user 0.139s	sys 0.024s Metrics: {"bytes_written":12307492,"cfile_init":1,"compiler_manager_pool.queue_time_us":215,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":283,"dirs.run_wall_time_us":865,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42497,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":135,"threads_started":1,"update_count":1500}
I20260812 06:16:54.967507 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71): free 8725963 bytes of WAL
I20260812 06:16:54.967967 16220 log_reader.cc:385] T 16e2f245008e4c42a8e1a88aa81c0b71: removed 1 log segments from log reader
I20260812 06:16:54.968050 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000001 (ops 1-6)
I20260812 06:16:54.970904 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:54.971259 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling UndoDeltaBlockGCOp(16e2f245008e4c42a8e1a88aa81c0b71): 12308960 bytes on disk
I20260812 06:16:54.971901 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: UndoDeltaBlockGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:16:54.972401 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:54.991933 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.019s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.992424 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:55.134997 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.142s	user 0.095s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":706,"lbm_read_time_us":8892,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28186,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":348,"threads_started":5,"update_count":2000}
I20260812 06:16:55.135548 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=10.126437
I20260812 06:16:55.184597 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.049s	user 0.038s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19792,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.185148 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:55.196609 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.197394 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:55.323966 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.126s	user 0.100s	sys 0.023s 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":227,"lbm_read_time_us":9022,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25132,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.324478 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=10.126437
I20260812 06:16:55.369742 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.045s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16783,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.370251 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:55.383757 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4585,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.384461 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:55.520442 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.136s	user 0.111s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1416,"lbm_read_time_us":11735,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26565,"lbm_writes_lt_1ms":443,"mutex_wait_us":559,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:55.521096 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=10.126437
I20260812 06:16:55.574357 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.053s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17098,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.574954 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:55.591507 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.591975 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:55.743299 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.151s	user 0.103s	sys 0.048s 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":284,"lbm_read_time_us":11402,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24305,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2000}
I20260812 06:16:55.743940 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=10.126437
I20260812 06:16:55.786263 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.042s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15555,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.786737 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:55.800702 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.801455 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:55.929572 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.128s	user 0.091s	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":277,"lbm_read_time_us":11352,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25377,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":53888,"update_count":2000}
I20260812 06:16:55.930208 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=10.126437
I20260812 06:16:55.975603 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.045s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16306,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.976128 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:55.988207 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.988878 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:56.113989 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.125s	user 0.112s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1119,"lbm_read_time_us":9654,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25926,"lbm_writes_lt_1ms":443,"mutex_wait_us":359,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2000}
I20260812 06:16:56.114562 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=10.126437
I20260812 06:16:56.162137 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.047s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17751,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.162676 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:56.175447 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.176060 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushMRSOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:56.207302 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushMRSOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.031s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1422,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2067,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:56.208209 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71): free 115943114 bytes of WAL
I20260812 06:16:56.208527 16220 log_reader.cc:385] T 16e2f245008e4c42a8e1a88aa81c0b71: removed 11 log segments from log reader
I20260812 06:16:56.208599 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000002 (ops 7-11)
I20260812 06:16:56.208658 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000003 (ops 12-16)
I20260812 06:16:56.208688 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000004 (ops 17-21)
I20260812 06:16:56.208732 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000005 (ops 22-26)
I20260812 06:16:56.208784 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000006 (ops 27-31)
I20260812 06:16:56.208827 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000007 (ops 32-36)
I20260812 06:16:56.208854 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000008 (ops 37-41)
I20260812 06:16:56.208891 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000009 (ops 42-46)
I20260812 06:16:56.208926 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000010 (ops 47-51)
I20260812 06:16:56.208959 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000011 (ops 52-56)
I20260812 06:16:56.208992 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000012 (ops 57-61)
I20260812 06:16:56.244971 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.037s	user 0.001s	sys 0.035s Metrics: {}
I20260812 06:16:56.245446 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:56.263616 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.018s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.264079 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71): free 12017983 bytes of WAL
I20260812 06:16:56.264305 16220 log_reader.cc:385] T 16e2f245008e4c42a8e1a88aa81c0b71: removed 1 log segments from log reader
I20260812 06:16:56.264354 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000013 (ops 62-66)
I20260812 06:16:56.267208 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:56.267699 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling UndoDeltaBlockGCOp(16e2f245008e4c42a8e1a88aa81c0b71): 448 bytes on disk
I20260812 06:16:56.269416 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: UndoDeltaBlockGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":125,"lbm_reads_lt_1ms":4}
I20260812 06:16:56.270008 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:56.285164 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.285693 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:56.454398 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.169s	user 0.136s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836371,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1234,"lbm_read_time_us":12369,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33337,"lbm_writes_lt_1ms":643,"mutex_wait_us":451,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:16:56.454905 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=14.095187
I20260812 06:16:56.511868 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.057s	user 0.016s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26026,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.512459 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:56.528846 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.016s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6432,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.529459 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:56.689836 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.160s	user 0.127s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1016,"lbm_read_time_us":10142,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30955,"lbm_writes_lt_1ms":543,"mutex_wait_us":332,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:16:56.690531 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=12.110812
I20260812 06:16:56.732748 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.042s	user 0.028s	sys 0.012s Metrics: {"bytes_written":13620266,"delete_count":0,"lbm_write_time_us":18089,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:16:56.736339 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.196750
I20260812 06:16:56.752202 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.016s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3610,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:16:56.752815 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:56.927618 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.175s	user 0.122s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631284,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":897,"lbm_read_time_us":11455,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29612,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.928337 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=14.095187
I20260812 06:16:57.015926 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.087s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":58415,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.016476 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:57.033953 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.034516 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:57.216884 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.182s	user 0.140s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":961,"lbm_read_time_us":13445,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29865,"lbm_writes_lt_1ms":543,"mutex_wait_us":416,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:57.217514 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=14.095187
I20260812 06:16:57.275408 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.058s	user 0.034s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25624,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.275995 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:57.290796 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.291286 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:57.482882 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.191s	user 0.113s	sys 0.072s 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":280,"lbm_read_time_us":11258,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31592,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:57.483610 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=14.095187
I20260812 06:16:57.538427 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.055s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25027,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.539081 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:57.565331 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.026s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.565899 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:57.576881 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4148,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.577442 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:57.792523 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.215s	user 0.147s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836255,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":136,"lbm_read_time_us":16755,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37106,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":3000}
I20260812 06:16:57.793265 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=14.095187
I20260812 06:16:57.846588 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.053s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19175,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.847235 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:57.863409 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.864174 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushMRSOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:57.915593 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushMRSOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.051s	user 0.044s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":296,"dirs.run_wall_time_us":1484,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2081,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:57.916589 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71): free 121006388 bytes of WAL
I20260812 06:16:57.916913 16220 log_reader.cc:385] T 16e2f245008e4c42a8e1a88aa81c0b71: removed 12 log segments from log reader
I20260812 06:16:57.916989 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000014 (ops 67-71)
I20260812 06:16:57.917048 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000015 (ops 72-76)
I20260812 06:16:57.917111 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000016 (ops 77-81)
I20260812 06:16:57.917150 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000017 (ops 82-86)
I20260812 06:16:57.917193 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000018 (ops 87-91)
I20260812 06:16:57.917236 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000019 (ops 92-96)
I20260812 06:16:57.917279 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000020 (ops 97-100)
I20260812 06:16:57.917320 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000021 (ops 101-105)
I20260812 06:16:57.917361 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000022 (ops 106-110)
I20260812 06:16:57.917402 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000023 (ops 111-115)
I20260812 06:16:57.917443 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000024 (ops 116-120)
I20260812 06:16:57.917483 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000025 (ops 121-125)
I20260812 06:16:57.949743 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.033s	user 0.001s	sys 0.031s Metrics: {}
I20260812 06:16:57.950323 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=3.181125
I20260812 06:16:57.971092 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.021s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7904,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:57.971691 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling UndoDeltaBlockGCOp(16e2f245008e4c42a8e1a88aa81c0b71): 492 bytes on disk
I20260812 06:16:57.972275 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: UndoDeltaBlockGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:16:57.972919 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:57.987648 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5336,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.988276 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:58.261240 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.273s	user 0.172s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2418,"lbm_read_time_us":17240,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45412,"lbm_writes_lt_1ms":743,"mutex_wait_us":1577,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":113,"threads_started":1,"update_count":3500}
I20260812 06:16:58.262223 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=18.063937
I20260812 06:16:58.342536 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.080s	user 0.046s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":32785,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:58.343166 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:58.360240 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.361018 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:58.564821 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.204s	user 0.123s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836138,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1381,"lbm_read_time_us":13864,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32905,"lbm_writes_lt_1ms":643,"mutex_wait_us":380,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:16:58.565702 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=16.079562
I20260812 06:16:58.630589 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.065s	user 0.031s	sys 0.022s Metrics: {"bytes_written":17722675,"delete_count":0,"lbm_write_time_us":24722,"lbm_writes_lt_1ms":435,"mutex_wait_us":30,"reinsert_count":0,"update_count":2160}
I20260812 06:16:58.631206 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:58.643999 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.013s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3335,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:16:58.644464 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:58.655159 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3783,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.655735 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:58.877508 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.222s	user 0.166s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836224,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":675,"lbm_read_time_us":15337,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37721,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":3000}
I20260812 06:16:58.882421 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=15.087375
I20260812 06:16:58.950749 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.068s	user 0.037s	sys 0.012s Metrics: {"bytes_written":17394482,"delete_count":0,"lbm_write_time_us":22524,"lbm_writes_lt_1ms":427,"reinsert_count":0,"update_count":2120}
I20260812 06:16:58.951231 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=5.165500
I20260812 06:16:58.971105 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.020s	user 0.017s	sys 0.000s Metrics: {"bytes_written":7220501,"delete_count":0,"lbm_write_time_us":8261,"lbm_writes_lt_1ms":179,"reinsert_count":0,"update_count":880}
I20260812 06:16:58.971629 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:59.193617 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.222s	user 0.144s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836140,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1423,"lbm_read_time_us":13343,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36727,"lbm_writes_lt_1ms":643,"mutex_wait_us":312,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":3000}
I20260812 06:16:59.194463 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=18.063937
I20260812 06:16:59.268206 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.073s	user 0.029s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26430,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:59.268802 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:59.280202 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4383,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.281064 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:59.491765 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.210s	user 0.148s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836138,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":15339,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33814,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":3000}
I20260812 06:16:59.492519 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=14.095187
I20260812 06:16:59.556615 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.056s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22175,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.557222 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:59.569166 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.012s	user 0.007s	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:16:59.569674 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushMRSOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:59.597222 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushMRSOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.027s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1489,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1988,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:59.597926 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71): free 133024646 bytes of WAL
I20260812 06:16:59.598171 16220 log_reader.cc:385] T 16e2f245008e4c42a8e1a88aa81c0b71: removed 13 log segments from log reader
I20260812 06:16:59.598218 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000026 (ops 126-130)
I20260812 06:16:59.598248 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000027 (ops 131-135)
I20260812 06:16:59.598317 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000028 (ops 136-140)
I20260812 06:16:59.598377 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000029 (ops 141-145)
I20260812 06:16:59.598441 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000030 (ops 146-150)
I20260812 06:16:59.598471 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000031 (ops 151-155)
I20260812 06:16:59.598511 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000032 (ops 156-160)
I20260812 06:16:59.598551 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000033 (ops 161-164)
I20260812 06:16:59.598591 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000034 (ops 165-169)
I20260812 06:16:59.598631 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000035 (ops 170-174)
I20260812 06:16:59.598671 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000036 (ops 175-179)
I20260812 06:16:59.598716 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000037 (ops 180-184)
I20260812 06:16:59.598758 16220 log.cc:1079] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/16e2f245008e4c42a8e1a88aa81c0b71/wal-000000038 (ops 185-189)
I20260812 06:16:59.631009 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: LogGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:16:59.631520 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling UndoDeltaBlockGCOp(16e2f245008e4c42a8e1a88aa81c0b71): 483 bytes on disk
I20260812 06:16:59.632124 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: UndoDeltaBlockGCOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:16:59.632709 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=3.181125
I20260812 06:16:59.654709 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.022s	user 0.016s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7388,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:59.655256 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=2.188937
I20260812 06:16:59.668470 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4711,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:59.669433 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:16:59.842993 16040 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.172s	user 1.903s	sys 0.142s
I20260812 06:16:59.895462 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.226s	user 0.176s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938776,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":19892,"lbm_reads_lt_1ms":770,"lbm_write_time_us":41806,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":3500}
I20260812 06:16:59.895967 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=14.095187
I20260812 06:16:59.932834 16040 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.089s	user 0.006s	sys 0.000s
I20260812 06:16:59.933614 16040 tablet_server.cc:179] TabletServer@127.15.170.1:0 shutting down...
I20260812 06:16:59.941366 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: FlushDeltaMemStoresOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.045s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20762,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.942160 16337 maintenance_manager.cc:419] P a16c6e288cd644c6b024cefad8f9da91: Scheduling MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71): perf score=1.000000
I20260812 06:17:00.056929 16220 maintenance_manager.cc:643] P a16c6e288cd644c6b024cefad8f9da91: MajorDeltaCompactionOp(16e2f245008e4c42a8e1a88aa81c0b71) complete. Timing: real 0.115s	user 0.077s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1685,"lbm_read_time_us":9530,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23397,"lbm_writes_lt_1ms":443,"mutex_wait_us":468,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:17:00.057825 16040 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:00.058265 16040 tablet_replica.cc:333] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91: stopping tablet replica
I20260812 06:17:00.058547 16040 raft_consensus.cc:2243] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:00.058845 16040 raft_consensus.cc:2272] T 16e2f245008e4c42a8e1a88aa81c0b71 P a16c6e288cd644c6b024cefad8f9da91 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:00.074115 16040 tablet_server.cc:196] TabletServer@127.15.170.1:0 shutdown complete.
I20260812 06:17:00.096993 16040 master.cc:562] Master@127.15.170.62:39619 shutting down...
I20260812 06:17:00.101867 16040 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:00.102085 16040 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:00.102195 16040 tablet_replica.cc:333] T 00000000000000000000000000000000 P dbe273a3928a4ac5a2defd389343a05a: stopping tablet replica
I20260812 06:17:00.114774 16040 master.cc:584] Master@127.15.170.62:39619 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5814 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:00.237936 16040 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.170.62:37913
I20260812 06:17:00.238453 16040 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:00.241261 16398 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:00.241294 16403 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:00.241268 16040 server_base.cc:1061] running on GCE node
W20260812 06:17:00.241272 16397 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:00.241626 16040 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:00.241672 16040 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:00.241688 16040 hybrid_clock.cc:648] HybridClock initialized: now 1786515420241687 us; error 0 us; skew 500 ppm
I20260812 06:17:00.242722 16040 webserver.cc:533] Webserver started at http://127.15.170.62:33581/ using document root <none> and password file <none>
I20260812 06:17:00.242918 16040 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:00.242992 16040 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:00.243083 16040 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:00.243522 16040 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/master-0-root/instance:
uuid: "c386b110abb742b9a514a987177fb072"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-g170"
I20260812 06:17:00.245954 16040 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:00.247123 16410 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.247412 16040 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:00.247490 16040 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/master-0-root
uuid: "c386b110abb742b9a514a987177fb072"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-g170"
I20260812 06:17:00.247550 16040 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:00.265415 16040 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:00.265846 16040 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:00.271894 16040 rpc_server.cc:307] RPC server started. Bound to: 127.15.170.62:37913
I20260812 06:17:00.279186 16501 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.170.62:37913 every 8 connection(s)
I20260812 06:17:00.279786 16502 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:00.281908 16502 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072: Bootstrap starting.
I20260812 06:17:00.282783 16502 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:00.284034 16502 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072: No bootstrap required, opened a new log
I20260812 06:17:00.284520 16502 raft_consensus.cc:359] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c386b110abb742b9a514a987177fb072" member_type: VOTER }
I20260812 06:17:00.284644 16502 raft_consensus.cc:385] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:00.284755 16502 raft_consensus.cc:740] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c386b110abb742b9a514a987177fb072, State: Initialized, Role: FOLLOWER
I20260812 06:17:00.284988 16502 consensus_queue.cc:260] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [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: "c386b110abb742b9a514a987177fb072" member_type: VOTER }
I20260812 06:17:00.285120 16502 raft_consensus.cc:399] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:00.285172 16502 raft_consensus.cc:493] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:00.285231 16502 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:00.285984 16502 raft_consensus.cc:515] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c386b110abb742b9a514a987177fb072" member_type: VOTER }
I20260812 06:17:00.286177 16502 leader_election.cc:304] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [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: c386b110abb742b9a514a987177fb072; no voters: 
I20260812 06:17:00.286439 16502 leader_election.cc:290] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:00.286619 16515 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:00.286940 16515 raft_consensus.cc:697] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 1 LEADER]: Becoming Leader. State: Replica: c386b110abb742b9a514a987177fb072, State: Running, Role: LEADER
I20260812 06:17:00.286970 16502 sys_catalog.cc:565] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:00.287094 16515 consensus_queue.cc:237] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [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: "c386b110abb742b9a514a987177fb072" member_type: VOTER }
I20260812 06:17:00.287691 16517 sys_catalog.cc:455] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c386b110abb742b9a514a987177fb072. Latest consensus state: current_term: 1 leader_uuid: "c386b110abb742b9a514a987177fb072" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c386b110abb742b9a514a987177fb072" member_type: VOTER } }
I20260812 06:17:00.287798 16517 sys_catalog.cc:458] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:00.288000 16516 sys_catalog.cc:455] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c386b110abb742b9a514a987177fb072" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c386b110abb742b9a514a987177fb072" member_type: VOTER } }
I20260812 06:17:00.288112 16516 sys_catalog.cc:458] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:00.288358 16525 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:00.289479 16525 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:00.289693 16040 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:00.292021 16525 catalog_manager.cc:1383] Generated new cluster ID: 6f03674b3ec3449787aad143ed872909
I20260812 06:17:00.292110 16525 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:00.303768 16525 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:00.304420 16525 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:00.315392 16525 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072: Generated new TSK 0
I20260812 06:17:00.315632 16525 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:00.322108 16040 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:00.324043 16548 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:00.324056 16543 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:00.324152 16040 server_base.cc:1061] running on GCE node
W20260812 06:17:00.324067 16542 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:00.324486 16040 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:00.324532 16040 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:00.324548 16040 hybrid_clock.cc:648] HybridClock initialized: now 1786515420324547 us; error 0 us; skew 500 ppm
I20260812 06:17:00.325512 16040 webserver.cc:533] Webserver started at http://127.15.170.1:34711/ using document root <none> and password file <none>
I20260812 06:17:00.325704 16040 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:00.325778 16040 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:00.325865 16040 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:00.326287 16040 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/instance:
uuid: "430487a92d624cbbab7c7d6e4fc3797e"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-g170"
I20260812 06:17:00.327919 16040 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:00.328998 16554 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.329227 16040 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:00.329316 16040 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root
uuid: "430487a92d624cbbab7c7d6e4fc3797e"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-g170"
I20260812 06:17:00.329407 16040 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:00.349664 16040 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:00.350127 16040 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:00.350493 16040 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:00.351015 16040 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:00.351079 16040 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.351135 16040 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:00.351187 16040 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.355751 16040 rpc_server.cc:307] RPC server started. Bound to: 127.15.170.1:37217
I20260812 06:17:00.355836 16663 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.170.1:37217 every 8 connection(s)
I20260812 06:17:00.364815 16665 heartbeater.cc:344] Connected to a master server at 127.15.170.62:37913
I20260812 06:17:00.364992 16665 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:00.365314 16665 heartbeater.cc:507] Master 127.15.170.62:37913 requested a full tablet report, sending...
I20260812 06:17:00.366052 16437 ts_manager.cc:194] Registered new tserver with Master: 430487a92d624cbbab7c7d6e4fc3797e (127.15.170.1:37217)
I20260812 06:17:00.366266 16040 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010017292s
I20260812 06:17:00.367094 16437 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34268
I20260812 06:17:00.374076 16437 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34278:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:00.384058 16608 tablet_service.cc:1511] Processing CreateTablet for tablet f1314bd26d034f3b87b63476a5c101d1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ddd7171c503a4977a590180e7e1ce3dd]), partition=
I20260812 06:17:00.384382 16608 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f1314bd26d034f3b87b63476a5c101d1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:00.386698 16683 tablet_bootstrap.cc:492] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Bootstrap starting.
I20260812 06:17:00.387595 16683 tablet_bootstrap.cc:654] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:00.389014 16683 tablet_bootstrap.cc:492] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: No bootstrap required, opened a new log
I20260812 06:17:00.389127 16683 ts_tablet_manager.cc:1403] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:00.389590 16683 raft_consensus.cc:359] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "430487a92d624cbbab7c7d6e4fc3797e" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 37217 } }
I20260812 06:17:00.389701 16683 raft_consensus.cc:385] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:00.389748 16683 raft_consensus.cc:740] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 430487a92d624cbbab7c7d6e4fc3797e, State: Initialized, Role: FOLLOWER
I20260812 06:17:00.389884 16683 consensus_queue.cc:260] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [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: "430487a92d624cbbab7c7d6e4fc3797e" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 37217 } }
I20260812 06:17:00.389979 16683 raft_consensus.cc:399] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:00.390025 16683 raft_consensus.cc:493] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:00.390079 16683 raft_consensus.cc:3060] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:00.390803 16683 raft_consensus.cc:515] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "430487a92d624cbbab7c7d6e4fc3797e" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 37217 } }
I20260812 06:17:00.390960 16683 leader_election.cc:304] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [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: 430487a92d624cbbab7c7d6e4fc3797e; no voters: 
I20260812 06:17:00.391184 16683 leader_election.cc:290] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:00.391362 16689 raft_consensus.cc:2804] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:00.391582 16665 heartbeater.cc:499] Master 127.15.170.62:37913 was elected leader, sending a full tablet report...
I20260812 06:17:00.391628 16683 ts_tablet_manager.cc:1434] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:00.391664 16689 raft_consensus.cc:697] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 1 LEADER]: Becoming Leader. State: Replica: 430487a92d624cbbab7c7d6e4fc3797e, State: Running, Role: LEADER
I20260812 06:17:00.391891 16689 consensus_queue.cc:237] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [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: "430487a92d624cbbab7c7d6e4fc3797e" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 37217 } }
I20260812 06:17:00.393386 16437 catalog_manager.cc:5719] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e reported cstate change: term changed from 0 to 1, leader changed from <none> to 430487a92d624cbbab7c7d6e4fc3797e (127.15.170.1). New cstate: current_term: 1 leader_uuid: "430487a92d624cbbab7c7d6e4fc3797e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "430487a92d624cbbab7c7d6e4fc3797e" member_type: VOTER last_known_addr { host: "127.15.170.1" port: 37217 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:00.453513 16040 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.011s	sys 0.012s
I20260812 06:17:00.606769 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushMRSOp(f1314bd26d034f3b87b63476a5c101d1): perf score=19.054940
I20260812 06:17:00.782338 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushMRSOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.175s	user 0.142s	sys 0.032s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":959,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43181,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":2304,"update_count":1550}
I20260812 06:17:00.783119 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling LogGCOp(f1314bd26d034f3b87b63476a5c101d1): free 20743880 bytes of WAL
I20260812 06:17:00.783390 16561 log_reader.cc:385] T f1314bd26d034f3b87b63476a5c101d1: removed 2 log segments from log reader
I20260812 06:17:00.783440 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000001 (ops 1-6)
I20260812 06:17:00.783473 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000002 (ops 7-11)
I20260812 06:17:00.789273 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: LogGCOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:00.789844 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling UndoDeltaBlockGCOp(f1314bd26d034f3b87b63476a5c101d1): 16411396 bytes on disk
I20260812 06:17:00.790582 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: UndoDeltaBlockGCOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.791219 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:00.804513 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5021,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.805004 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:00.977674 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.172s	user 0.112s	sys 0.060s 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":496,"lbm_read_time_us":12708,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27604,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":347,"threads_started":5,"update_count":2000}
I20260812 06:17:00.978243 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=11.118625
I20260812 06:17:01.026714 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.048s	user 0.030s	sys 0.016s Metrics: {"bytes_written":12594659,"delete_count":0,"lbm_write_time_us":20756,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:17:01.027320 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:01.056110 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.029s	user 0.000s	sys 0.015s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":6611,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:01.056586 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:01.080569 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.024s	user 0.005s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.081224 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:01.292027 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.211s	user 0.153s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1061,"lbm_read_time_us":17361,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32946,"lbm_writes_lt_1ms":543,"mutex_wait_us":312,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:17:01.292665 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=14.095187
I20260812 06:17:01.352222 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.059s	user 0.039s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27083,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.352824 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:01.393987 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.041s	user 0.010s	sys 0.019s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5756,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.394670 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:01.412640 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.413365 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:01.649652 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.236s	user 0.137s	sys 0.093s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":658,"lbm_read_time_us":17876,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37311,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":3000}
I20260812 06:17:01.650336 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=14.095187
I20260812 06:17:01.725970 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.075s	user 0.051s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29112,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.726570 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:01.737744 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.738168 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:01.928592 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.190s	user 0.126s	sys 0.060s 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":2330,"lbm_read_time_us":13194,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31037,"lbm_writes_lt_1ms":543,"mutex_wait_us":718,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:01.929323 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=11.118625
I20260812 06:17:01.988067 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.059s	user 0.022s	sys 0.018s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":32694,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.988571 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:01.999830 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.000411 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:02.027933 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.027s	user 0.013s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5195,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:02.028541 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:02.224579 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.196s	user 0.124s	sys 0.066s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":303,"lbm_read_time_us":13906,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32403,"lbm_writes_lt_1ms":543,"mutex_wait_us":134,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:17:02.225428 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=11.118625
I20260812 06:17:02.263500 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.038s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15748,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:02.264045 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:02.279418 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5396,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:02.280122 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushMRSOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:02.342048 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushMRSOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.062s	user 0.034s	sys 0.005s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":279,"dirs.run_wall_time_us":1235,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1804,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":21888}
I20260812 06:17:02.342667 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling UndoDeltaBlockGCOp(f1314bd26d034f3b87b63476a5c101d1): 473 bytes on disk
I20260812 06:17:02.343016 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: UndoDeltaBlockGCOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:17:02.343429 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=3.181125
I20260812 06:17:02.368058 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.024s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4515,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:02.368531 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling LogGCOp(f1314bd26d034f3b87b63476a5c101d1): free 121006437 bytes of WAL
I20260812 06:17:02.368798 16561 log_reader.cc:385] T f1314bd26d034f3b87b63476a5c101d1: removed 12 log segments from log reader
I20260812 06:17:02.368868 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000003 (ops 12-16)
I20260812 06:17:02.368924 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000004 (ops 17-21)
I20260812 06:17:02.368983 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000005 (ops 22-26)
I20260812 06:17:02.369024 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000006 (ops 27-30)
I20260812 06:17:02.369060 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000007 (ops 31-35)
I20260812 06:17:02.369098 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000008 (ops 36-40)
I20260812 06:17:02.369150 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000009 (ops 41-45)
I20260812 06:17:02.369189 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000010 (ops 46-50)
I20260812 06:17:02.369225 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000011 (ops 51-55)
I20260812 06:17:02.369261 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000012 (ops 56-60)
I20260812 06:17:02.369299 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000013 (ops 61-65)
I20260812 06:17:02.369336 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000014 (ops 66-70)
I20260812 06:17:02.398264 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: LogGCOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.030s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:17:02.398636 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:02.425034 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.026s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.425601 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:02.436465 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:02.437009 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:02.732718 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.295s	user 0.165s	sys 0.117s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979852,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":264,"lbm_read_time_us":18888,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43819,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":331,"threads_started":6,"update_count":3500}
I20260812 06:17:02.733459 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=22.032687
I20260812 06:17:02.814913 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.081s	user 0.053s	sys 0.026s Metrics: {"bytes_written":24614720,"delete_count":0,"lbm_write_time_us":36848,"lbm_writes_lt_1ms":603,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:17:02.815588 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:02.829823 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.014s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.830291 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:03.088568 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.258s	user 0.155s	sys 0.093s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979507,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":147,"lbm_read_time_us":19016,"lbm_reads_lt_1ms":772,"lbm_write_time_us":46472,"lbm_writes_lt_1ms":743,"mutex_wait_us":94,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":3500}
I20260812 06:17:03.089396 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=22.032687
I20260812 06:17:03.166222 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.077s	user 0.057s	sys 0.018s Metrics: {"bytes_written":24614723,"delete_count":0,"lbm_write_time_us":34159,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:17:03.166734 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:03.193930 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.027s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.194401 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:03.205786 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.206341 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:03.433585 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.227s	user 0.173s	sys 0.045s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082040,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":240,"lbm_read_time_us":18899,"lbm_reads_lt_1ms":873,"lbm_write_time_us":44584,"lbm_writes_lt_1ms":843,"mutex_wait_us":21,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":28288,"update_count":4000}
I20260812 06:17:03.434319 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=18.063937
I20260812 06:17:03.491036 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.057s	user 0.047s	sys 0.004s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":23276,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:03.491562 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:03.502579 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.503088 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:03.683631 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.180s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1215,"lbm_read_time_us":14312,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35343,"lbm_writes_lt_1ms":643,"mutex_wait_us":75,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3000}
I20260812 06:17:03.684310 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=14.095187
I20260812 06:17:03.740379 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.056s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21557,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.740996 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:03.757041 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5887,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.757648 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushMRSOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:03.785478 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushMRSOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.028s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1525,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1603,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":25472}
I20260812 06:17:03.786106 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling LogGCOp(f1314bd26d034f3b87b63476a5c101d1): free 112239314 bytes of WAL
I20260812 06:17:03.786341 16561 log_reader.cc:385] T f1314bd26d034f3b87b63476a5c101d1: removed 11 log segments from log reader
I20260812 06:17:03.786388 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000015 (ops 71-75)
I20260812 06:17:03.786413 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000016 (ops 76-80)
I20260812 06:17:03.786453 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000017 (ops 81-85)
I20260812 06:17:03.786499 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000018 (ops 86-90)
I20260812 06:17:03.786546 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000019 (ops 91-95)
I20260812 06:17:03.786585 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000020 (ops 96-100)
I20260812 06:17:03.786612 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000021 (ops 101-104)
I20260812 06:17:03.786675 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000022 (ops 105-109)
I20260812 06:17:03.786713 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000023 (ops 110-114)
I20260812 06:17:03.786751 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000024 (ops 115-119)
I20260812 06:17:03.786789 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000025 (ops 120-124)
I20260812 06:17:03.813038 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: LogGCOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:03.813532 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:03.835053 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.021s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6476,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.835508 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling UndoDeltaBlockGCOp(f1314bd26d034f3b87b63476a5c101d1): 447 bytes on disk
I20260812 06:17:03.835914 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: UndoDeltaBlockGCOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.836407 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:03.846992 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.847751 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:04.046711 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.199s	user 0.145s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4099,"lbm_read_time_us":14258,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39549,"lbm_writes_lt_1ms":743,"mutex_wait_us":1751,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:17:04.047569 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=14.095187
I20260812 06:17:04.095010 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.047s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21482,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.095644 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:04.113881 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.018s	user 0.000s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.114449 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:04.288925 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.174s	user 0.128s	sys 0.038s 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":342,"lbm_read_time_us":9859,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30931,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:17:04.289610 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=14.095187
I20260812 06:17:04.343937 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.054s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22707,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.344516 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:04.500291 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.156s	user 0.108s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":133,"lbm_read_time_us":8533,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26044,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":69376,"update_count":2000}
I20260812 06:17:04.500939 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=14.095187
I20260812 06:17:04.546528 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.045s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19908,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.546981 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:04.558519 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4225,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.559031 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:04.755862 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.197s	user 0.140s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1005,"lbm_read_time_us":11181,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36106,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:17:04.756928 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=14.095187
I20260812 06:17:04.810351 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.053s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25476,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.810914 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:04.826118 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.015s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.826560 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:04.994894 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.168s	user 0.117s	sys 0.048s 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":528,"lbm_read_time_us":10084,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33718,"lbm_writes_lt_1ms":543,"mutex_wait_us":302,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:17:04.995458 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=11.118625
I20260812 06:17:05.036968 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.041s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17741,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:05.037626 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:05.057633 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.020s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5515,"lbm_writes_lt_1ms":93,"mutex_wait_us":2,"reinsert_count":0,"update_count":450}
I20260812 06:17:05.058075 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:05.068714 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.010s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.069185 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:05.223975 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.154s	user 0.110s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":346,"lbm_read_time_us":10458,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31566,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:17:05.224653 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=10.126437
I20260812 06:17:05.263025 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.038s	user 0.027s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16784,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:05.263665 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:05.281226 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.281678 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushMRSOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:05.316174 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushMRSOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.034s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":280,"dirs.run_wall_time_us":1468,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1681,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:05.317075 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling LogGCOp(f1314bd26d034f3b87b63476a5c101d1): free 132118513 bytes of WAL
I20260812 06:17:05.317389 16561 log_reader.cc:385] T f1314bd26d034f3b87b63476a5c101d1: removed 13 log segments from log reader
I20260812 06:17:05.317456 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000026 (ops 125-129)
I20260812 06:17:05.317548 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000027 (ops 130-134)
I20260812 06:17:05.317620 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000028 (ops 135-139)
I20260812 06:17:05.317694 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000029 (ops 140-144)
I20260812 06:17:05.317739 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000030 (ops 145-148)
I20260812 06:17:05.317788 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000031 (ops 149-153)
I20260812 06:17:05.317837 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000032 (ops 154-158)
I20260812 06:17:05.317884 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000033 (ops 159-163)
I20260812 06:17:05.317931 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000034 (ops 164-168)
I20260812 06:17:05.317979 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000035 (ops 169-172)
I20260812 06:17:05.318039 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000036 (ops 173-177)
I20260812 06:17:05.318066 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000037 (ops 178-182)
I20260812 06:17:05.318094 16561 log.cc:1079] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: Deleting log segment in path: /tmp/dist-test-taskj9EyYY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515414396470-16040-0/minicluster-data/ts-0-root/wals/f1314bd26d034f3b87b63476a5c101d1/wal-000000038 (ops 183-186)
I20260812 06:17:05.351311 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: LogGCOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:05.351773 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling UndoDeltaBlockGCOp(f1314bd26d034f3b87b63476a5c101d1): 472 bytes on disk
I20260812 06:17:05.352243 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: UndoDeltaBlockGCOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:05.352897 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=6.157687
I20260812 06:17:05.393806 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.041s	user 0.024s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12883,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:05.394363 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=2.188937
I20260812 06:17:05.405697 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.406198 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:05.664928 16040 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.211s	user 1.945s	sys 0.168s
I20260812 06:17:05.673949 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.268s	user 0.169s	sys 0.093s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17684,"lbm_reads_lt_1ms":770,"lbm_write_time_us":42794,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3500}
I20260812 06:17:05.674520 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1): perf score=18.063937
I20260812 06:17:05.727479 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: FlushDeltaMemStoresOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.053s	user 0.031s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24954,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:05.728036 16667 maintenance_manager.cc:419] P 430487a92d624cbbab7c7d6e4fc3797e: Scheduling MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1): perf score=1.000000
I20260812 06:17:05.768241 16040 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.103s	user 0.001s	sys 0.000s
I20260812 06:17:05.769121 16040 tablet_server.cc:179] TabletServer@127.15.170.1:0 shutting down...
I20260812 06:17:05.883960 16561 maintenance_manager.cc:643] P 430487a92d624cbbab7c7d6e4fc3797e: MajorDeltaCompactionOp(f1314bd26d034f3b87b63476a5c101d1) complete. Timing: real 0.156s	user 0.085s	sys 0.067s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774572,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1470,"lbm_read_time_us":10468,"lbm_reads_lt_1ms":567,"lbm_write_time_us":24575,"lbm_writes_lt_1ms":543,"mutex_wait_us":491,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:05.884701 16040 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:05.884979 16040 tablet_replica.cc:333] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e: stopping tablet replica
I20260812 06:17:05.885143 16040 raft_consensus.cc:2243] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:05.885311 16040 raft_consensus.cc:2272] T f1314bd26d034f3b87b63476a5c101d1 P 430487a92d624cbbab7c7d6e4fc3797e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:05.889390 16040 tablet_server.cc:196] TabletServer@127.15.170.1:0 shutdown complete.
I20260812 06:17:05.932268 16040 master.cc:562] Master@127.15.170.62:37913 shutting down...
I20260812 06:17:05.936056 16040 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:05.936270 16040 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:05.936358 16040 tablet_replica.cc:333] T 00000000000000000000000000000000 P c386b110abb742b9a514a987177fb072: stopping tablet replica
I20260812 06:17:05.948815 16040 master.cc:584] Master@127.15.170.62:37913 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5821 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11636 ms total)

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