[==========] 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:18:59.852895 10833 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.148.126:33683
I20260812 06:18:59.853948 10833 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:18:59.854559 10833 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.861234 10844 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:18:59.861267 10850 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:18:59.861436 10833 server_base.cc:1061] running on GCE node
W20260812 06:18:59.861559 10845 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:18:59.862052 10833 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.862161 10833 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:18:59.862207 10833 hybrid_clock.cc:648] HybridClock initialized: now 1786515539862205 us; error 0 us; skew 500 ppm
I20260812 06:18:59.864058 10833 webserver.cc:533] Webserver started at http://127.10.148.126:40675/ using document root <none> and password file <none>
I20260812 06:18:59.864667 10833 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.864733 10833 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.864979 10833 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.866637 10833 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/master-0-root/instance:
uuid: "6a9e05b849ce4afa9db08b60c77f48e4"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-lkx2"
I20260812 06:18:59.870194 10833 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:59.872385 10859 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:18:59.873399 10833 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:59.873519 10833 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/master-0-root
uuid: "6a9e05b849ce4afa9db08b60c77f48e4"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-lkx2"
I20260812 06:18:59.873616 10833 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-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:18:59.902626 10833 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.903363 10833 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:18:59.903532 10833 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.911370 10833 rpc_server.cc:307] RPC server started. Bound to: 127.10.148.126:33683
I20260812 06:18:59.911381 10958 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.148.126:33683 every 8 connection(s)
I20260812 06:18:59.913879 10959 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:18:59.919731 10959 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4: Bootstrap starting.
I20260812 06:18:59.922284 10959 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:59.923224 10959 log.cc:826] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:59.925083 10959 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4: No bootstrap required, opened a new log
I20260812 06:18:59.928033 10959 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a9e05b849ce4afa9db08b60c77f48e4" member_type: VOTER }
I20260812 06:18:59.928224 10959 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:59.928279 10959 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6a9e05b849ce4afa9db08b60c77f48e4, State: Initialized, Role: FOLLOWER
I20260812 06:18:59.928905 10959 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [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: "6a9e05b849ce4afa9db08b60c77f48e4" member_type: VOTER }
I20260812 06:18:59.929075 10959 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:59.929127 10959 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:59.929235 10959 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:59.930044 10959 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a9e05b849ce4afa9db08b60c77f48e4" member_type: VOTER }
I20260812 06:18:59.930475 10959 leader_election.cc:304] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [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: 6a9e05b849ce4afa9db08b60c77f48e4; no voters: 
I20260812 06:18:59.930778 10959 leader_election.cc:290] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:59.930924 10963 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:59.931149 10963 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 1 LEADER]: Becoming Leader. State: Replica: 6a9e05b849ce4afa9db08b60c77f48e4, State: Running, Role: LEADER
I20260812 06:18:59.931545 10963 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [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: "6a9e05b849ce4afa9db08b60c77f48e4" member_type: VOTER }
I20260812 06:18:59.931869 10959 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:59.933416 10972 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6a9e05b849ce4afa9db08b60c77f48e4. Latest consensus state: current_term: 1 leader_uuid: "6a9e05b849ce4afa9db08b60c77f48e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a9e05b849ce4afa9db08b60c77f48e4" member_type: VOTER } }
I20260812 06:18:59.933575 10972 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.933879 10969 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6a9e05b849ce4afa9db08b60c77f48e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a9e05b849ce4afa9db08b60c77f48e4" member_type: VOTER } }
I20260812 06:18:59.933970 10969 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.934398 10833 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:59.933966 10994 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:59.936836 10994 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:59.941699 10994 catalog_manager.cc:1383] Generated new cluster ID: fe65c04a318b4d92b2ff5752ca34d2e4
I20260812 06:18:59.941772 10994 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:59.974278 10994 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:59.975215 10994 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:59.981297 10994 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4: Generated new TSK 0
I20260812 06:18:59.981973 10994 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:59.999712 10833 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:00.002981 10833 server_base.cc:1061] running on GCE node
W20260812 06:19:00.003062 11012 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:00.003038 11013 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:00.003333 11016 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:00.003526 10833 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:00.003578 10833 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:00.003594 10833 hybrid_clock.cc:648] HybridClock initialized: now 1786515540003594 us; error 0 us; skew 500 ppm
I20260812 06:19:00.004504 10833 webserver.cc:533] Webserver started at http://127.10.148.65:33203/ using document root <none> and password file <none>
I20260812 06:19:00.004691 10833 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:00.004745 10833 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:00.004827 10833 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:00.005203 10833 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/instance:
uuid: "39fc7e4391264dc68a01854bc800fd14"
format_stamp: "Formatted at 2026-08-12 06:19:00 on dist-test-slave-lkx2"
I20260812 06:19:00.006708 10833 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:00.007702 11024 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:00.007954 10833 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:00.008028 10833 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root
uuid: "39fc7e4391264dc68a01854bc800fd14"
format_stamp: "Formatted at 2026-08-12 06:19:00 on dist-test-slave-lkx2"
I20260812 06:19:00.008102 10833 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:00.020757 10833 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:00.021207 10833 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:00.021703 10833 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:00.022571 10833 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:00.022624 10833 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:00.022682 10833 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:00.022707 10833 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:00.029009 10833 rpc_server.cc:307] RPC server started. Bound to: 127.10.148.65:42211
I20260812 06:19:00.029171 11131 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.148.65:42211 every 8 connection(s)
I20260812 06:19:00.039654 11132 heartbeater.cc:344] Connected to a master server at 127.10.148.126:33683
I20260812 06:19:00.039922 11132 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:00.040413 11132 heartbeater.cc:507] Master 127.10.148.126:33683 requested a full tablet report, sending...
I20260812 06:19:00.041996 10889 ts_manager.cc:194] Registered new tserver with Master: 39fc7e4391264dc68a01854bc800fd14 (127.10.148.65:42211)
I20260812 06:19:00.042115 10833 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012459005s
I20260812 06:19:00.043496 10889 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33422
I20260812 06:19:00.051976 10889 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33424:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:00.067593 11065 tablet_service.cc:1511] Processing CreateTablet for tablet 90beaa09e886496998fd6af32e1cc5a8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e753919286014e80bf30af1311b002a9]), partition=
I20260812 06:19:00.068090 11065 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 90beaa09e886496998fd6af32e1cc5a8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:00.070377 11153 tablet_bootstrap.cc:492] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Bootstrap starting.
I20260812 06:19:00.071601 11153 tablet_bootstrap.cc:654] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:00.073124 11153 tablet_bootstrap.cc:492] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: No bootstrap required, opened a new log
I20260812 06:19:00.073213 11153 ts_tablet_manager.cc:1403] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:00.073710 11153 raft_consensus.cc:359] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39fc7e4391264dc68a01854bc800fd14" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 42211 } }
I20260812 06:19:00.073812 11153 raft_consensus.cc:385] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:00.073835 11153 raft_consensus.cc:740] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 39fc7e4391264dc68a01854bc800fd14, State: Initialized, Role: FOLLOWER
I20260812 06:19:00.073951 11153 consensus_queue.cc:260] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [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: "39fc7e4391264dc68a01854bc800fd14" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 42211 } }
I20260812 06:19:00.074021 11153 raft_consensus.cc:399] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:00.074046 11153 raft_consensus.cc:493] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:00.074093 11153 raft_consensus.cc:3060] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:00.074836 11153 raft_consensus.cc:515] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39fc7e4391264dc68a01854bc800fd14" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 42211 } }
I20260812 06:19:00.074983 11153 leader_election.cc:304] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [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: 39fc7e4391264dc68a01854bc800fd14; no voters: 
I20260812 06:19:00.075197 11153 leader_election.cc:290] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:00.075333 11155 raft_consensus.cc:2804] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:00.075587 11155 raft_consensus.cc:697] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 1 LEADER]: Becoming Leader. State: Replica: 39fc7e4391264dc68a01854bc800fd14, State: Running, Role: LEADER
I20260812 06:19:00.075641 11153 ts_tablet_manager.cc:1434] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:00.075748 11155 consensus_queue.cc:237] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [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: "39fc7e4391264dc68a01854bc800fd14" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 42211 } }
I20260812 06:19:00.076040 11132 heartbeater.cc:499] Master 127.10.148.126:33683 was elected leader, sending a full tablet report...
I20260812 06:19:00.078471 10889 catalog_manager.cc:5719] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 reported cstate change: term changed from 0 to 1, leader changed from <none> to 39fc7e4391264dc68a01854bc800fd14 (127.10.148.65). New cstate: current_term: 1 leader_uuid: "39fc7e4391264dc68a01854bc800fd14" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39fc7e4391264dc68a01854bc800fd14" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 42211 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:00.146914 10833 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.017s	sys 0.012s
I20260812 06:19:00.280085 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushMRSOp(90beaa09e886496998fd6af32e1cc5a8): perf score=19.054940
I20260812 06:19:00.438076 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushMRSOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.158s	user 0.117s	sys 0.035s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":205,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":936,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38441,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":111,"threads_started":1,"update_count":1500}
I20260812 06:19:00.439461 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling UndoDeltaBlockGCOp(90beaa09e886496998fd6af32e1cc5a8): 16411393 bytes on disk
I20260812 06:19:00.440104 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: UndoDeltaBlockGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:00.440600 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:00.451221 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":1887306,"delete_count":0,"lbm_write_time_us":2906,"lbm_writes_lt_1ms":49,"reinsert_count":0,"update_count":230}
I20260812 06:19:00.451797 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling LogGCOp(90beaa09e886496998fd6af32e1cc5a8): free 20743880 bytes of WAL
I20260812 06:19:00.452136 11033 log_reader.cc:385] T 90beaa09e886496998fd6af32e1cc5a8: removed 2 log segments from log reader
I20260812 06:19:00.452250 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000001 (ops 1-6)
I20260812 06:19:00.452375 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000002 (ops 7-11)
I20260812 06:19:00.457693 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: LogGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:00.458120 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.196750
I20260812 06:19:00.466997 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2215504,"delete_count":0,"lbm_write_time_us":2836,"lbm_writes_lt_1ms":57,"reinsert_count":0,"update_count":270}
I20260812 06:19:00.467461 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:00.605983 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.138s	user 0.109s	sys 0.024s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672302,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":580,"lbm_read_time_us":8388,"lbm_reads_lt_1ms":469,"lbm_write_time_us":23353,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":269,"threads_started":5,"update_count":2000}
I20260812 06:19:00.606494 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:00.650168 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.044s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14764,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.650631 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:00.660892 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3653,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.661437 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:00.783357 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.122s	user 0.110s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":291,"lbm_read_time_us":8357,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24367,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:00.783883 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:00.825276 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.041s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15588,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.825811 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:00.835917 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3712,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.836476 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:00.973748 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.137s	user 0.096s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":115,"lbm_read_time_us":9663,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27889,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:19:00.974226 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:01.012965 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.039s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13266,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.013512 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:01.024296 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.024950 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:01.161063 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.136s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":706,"lbm_read_time_us":10344,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22229,"lbm_writes_lt_1ms":443,"mutex_wait_us":325,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:19:01.161620 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:01.200567 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.039s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16293,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":1500}
I20260812 06:19:01.201160 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:01.217128 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.217638 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:01.339879 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.122s	user 0.098s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":784,"lbm_read_time_us":8609,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24225,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2000}
I20260812 06:19:01.340471 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:01.376919 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.036s	user 0.014s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14964,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.377435 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:01.389133 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.389632 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:01.509334 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.120s	user 0.099s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1084,"lbm_read_time_us":10228,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21726,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:19:01.510070 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:01.547049 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.037s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14252,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.547605 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:01.558151 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3793,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.558918 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushMRSOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:01.586907 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushMRSOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":92,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1323,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1462,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:01.587734 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling LogGCOp(90beaa09e886496998fd6af32e1cc5a8): free 112692372 bytes of WAL
I20260812 06:19:01.587971 11033 log_reader.cc:385] T 90beaa09e886496998fd6af32e1cc5a8: removed 11 log segments from log reader
I20260812 06:19:01.588020 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000003 (ops 12-16)
I20260812 06:19:01.588059 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000004 (ops 17-21)
I20260812 06:19:01.588092 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000005 (ops 22-26)
I20260812 06:19:01.588124 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000006 (ops 27-31)
I20260812 06:19:01.588153 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000007 (ops 32-36)
I20260812 06:19:01.588182 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000008 (ops 37-41)
I20260812 06:19:01.588213 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000009 (ops 42-46)
I20260812 06:19:01.588243 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000010 (ops 47-51)
I20260812 06:19:01.588272 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000011 (ops 52-56)
I20260812 06:19:01.588302 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000012 (ops 57-61)
I20260812 06:19:01.588330 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000013 (ops 62-66)
I20260812 06:19:01.611047 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: LogGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:01.611544 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=3.181125
I20260812 06:19:01.634307 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.023s	user 0.003s	sys 0.014s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6723,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:01.634821 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:01.644408 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.009s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3346,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:01.645058 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling UndoDeltaBlockGCOp(90beaa09e886496998fd6af32e1cc5a8): 447 bytes on disk
I20260812 06:19:01.645588 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: UndoDeltaBlockGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:01.646315 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:01.821499 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.175s	user 0.135s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":126,"lbm_read_time_us":13870,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31514,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:19:01.822126 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=14.095187
I20260812 06:19:01.878964 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.057s	user 0.027s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20562,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.879565 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:01.891778 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.892261 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:02.050047 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.157s	user 0.117s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":10395,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27853,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:02.050638 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=14.095187
I20260812 06:19:02.093377 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.043s	user 0.018s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16813,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.094063 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:02.246723 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.152s	user 0.103s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":191,"lbm_read_time_us":10555,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24825,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:19:02.247370 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=11.118625
I20260812 06:19:02.291934 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.044s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15422,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:02.292533 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:02.303124 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3595,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:02.303668 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:02.460592 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.157s	user 0.094s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":704,"lbm_read_time_us":10665,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25140,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.461210 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=11.118625
I20260812 06:19:02.500819 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17412,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:02.501446 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:02.516065 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5622,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:02.516768 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:02.639842 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.123s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":10265,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21766,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:19:02.640609 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:02.680889 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.040s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17645,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":1500}
I20260812 06:19:02.681358 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:02.691740 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3813,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.692399 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:02.817420 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.125s	user 0.092s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":770,"lbm_read_time_us":8878,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24212,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.818058 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:02.872915 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.055s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13991,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.873523 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:02.884131 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3905,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.884631 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:03.026959 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.142s	user 0.101s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":912,"lbm_read_time_us":11301,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22612,"lbm_writes_lt_1ms":443,"mutex_wait_us":119,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.027523 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:03.075322 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.048s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17017,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.075886 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:03.087229 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.087914 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushMRSOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:03.121524 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushMRSOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.033s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1166,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1522,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:03.122459 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling LogGCOp(90beaa09e886496998fd6af32e1cc5a8): free 132571311 bytes of WAL
I20260812 06:19:03.122726 11033 log_reader.cc:385] T 90beaa09e886496998fd6af32e1cc5a8: removed 13 log segments from log reader
I20260812 06:19:03.122779 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000014 (ops 67-71)
I20260812 06:19:03.122829 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000015 (ops 72-76)
I20260812 06:19:03.122862 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000016 (ops 77-81)
I20260812 06:19:03.122893 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000017 (ops 82-86)
I20260812 06:19:03.122923 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000018 (ops 87-90)
I20260812 06:19:03.122954 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000019 (ops 91-95)
I20260812 06:19:03.122983 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000020 (ops 96-100)
I20260812 06:19:03.123013 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000021 (ops 101-105)
I20260812 06:19:03.123042 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000022 (ops 106-110)
I20260812 06:19:03.123071 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000023 (ops 111-115)
I20260812 06:19:03.123101 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000024 (ops 116-120)
I20260812 06:19:03.123131 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000025 (ops 121-124)
I20260812 06:19:03.123159 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000026 (ops 125-129)
I20260812 06:19:03.149210 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: LogGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:03.149645 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=5.165500
I20260812 06:19:03.171411 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.022s	user 0.008s	sys 0.010s Metrics: {"bytes_written":6400017,"delete_count":0,"lbm_write_time_us":5823,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:19:03.171942 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling UndoDeltaBlockGCOp(90beaa09e886496998fd6af32e1cc5a8): 483 bytes on disk
I20260812 06:19:03.172649 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: UndoDeltaBlockGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:03.173249 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:03.179154 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":1707,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:19:03.179553 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:03.380558 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.201s	user 0.137s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877286,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":227,"lbm_read_time_us":14045,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33792,"lbm_writes_lt_1ms":643,"mutex_wait_us":142,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:19:03.381160 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=14.095187
I20260812 06:19:03.448654 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.067s	user 0.035s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22053,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.449299 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:03.459949 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.460587 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:03.638530 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.178s	user 0.124s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":154,"lbm_read_time_us":12738,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29573,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:03.639192 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=11.118625
I20260812 06:19:03.678656 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.039s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16678,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:03.679347 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:03.691272 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4087,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:03.691773 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:03.832741 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.141s	user 0.101s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":906,"lbm_read_time_us":9935,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25422,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:03.833588 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:03.876121 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.042s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17276,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.876681 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:03.893059 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.894018 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:04.014861 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.121s	user 0.096s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":8158,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23404,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:04.015614 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:04.050698 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.035s	user 0.008s	sys 0.025s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15115,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.051303 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:04.063036 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.063577 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:04.194483 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.130s	user 0.113s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":8302,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26736,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:04.195202 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:04.246793 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.051s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17420,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.247344 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:04.258019 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3917,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.258571 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:04.399441 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.141s	user 0.103s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":10794,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22035,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:19:04.400187 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:04.443001 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.043s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14787,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.443686 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:04.454377 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.455093 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:04.570044 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.115s	user 0.078s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":8181,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20469,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:04.570603 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=10.126437
I20260812 06:19:04.607055 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.036s	user 0.026s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13610,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.607653 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=2.188937
I20260812 06:19:04.618381 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.619055 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushMRSOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:04.652714 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushMRSOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.033s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1179,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1486,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:04.653398 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling LogGCOp(90beaa09e886496998fd6af32e1cc5a8): free 121006705 bytes of WAL
I20260812 06:19:04.653636 11033 log_reader.cc:385] T 90beaa09e886496998fd6af32e1cc5a8: removed 12 log segments from log reader
I20260812 06:19:04.653682 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000027 (ops 130-134)
I20260812 06:19:04.653712 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000028 (ops 135-139)
I20260812 06:19:04.653743 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000029 (ops 140-144)
I20260812 06:19:04.653776 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000030 (ops 145-149)
I20260812 06:19:04.653808 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000031 (ops 150-154)
I20260812 06:19:04.653838 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000032 (ops 155-159)
I20260812 06:19:04.653872 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000033 (ops 160-164)
I20260812 06:19:04.653903 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000034 (ops 165-169)
I20260812 06:19:04.653935 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000035 (ops 170-174)
I20260812 06:19:04.653967 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000036 (ops 175-178)
I20260812 06:19:04.653999 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000037 (ops 179-183)
I20260812 06:19:04.654031 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000038 (ops 184-188)
I20260812 06:19:04.679388 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: LogGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:04.679806 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=3.181125
I20260812 06:19:04.696911 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":5087238,"delete_count":0,"lbm_write_time_us":6714,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:19:04.697353 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling LogGCOp(90beaa09e886496998fd6af32e1cc5a8): free 11564893 bytes of WAL
I20260812 06:19:04.697549 11033 log_reader.cc:385] T 90beaa09e886496998fd6af32e1cc5a8: removed 1 log segments from log reader
I20260812 06:19:04.697593 11033 log.cc:1079] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/90beaa09e886496998fd6af32e1cc5a8/wal-000000039 (ops 189-192)
I20260812 06:19:04.699510 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: LogGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:04.699821 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling UndoDeltaBlockGCOp(90beaa09e886496998fd6af32e1cc5a8): 482 bytes on disk
I20260812 06:19:04.700196 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: UndoDeltaBlockGCOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:04.700697 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.196750
I20260812 06:19:04.710161 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":3367,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:19:04.710587 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8): perf score=1.000000
I20260812 06:19:04.868980 10833 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.722s	user 1.751s	sys 0.116s
I20260812 06:19:04.871191 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: MajorDeltaCompactionOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.160s	user 0.118s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":269,"lbm_read_time_us":10606,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30794,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:19:04.871850 11135 maintenance_manager.cc:419] P 39fc7e4391264dc68a01854bc800fd14: Scheduling FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8): perf score=14.095187
I20260812 06:19:04.899935 10833 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.030s	user 0.001s	sys 0.000s
I20260812 06:19:04.901957 10833 tablet_server.cc:179] TabletServer@127.10.148.65:0 shutting down...
I20260812 06:19:04.914784 11033 maintenance_manager.cc:643] P 39fc7e4391264dc68a01854bc800fd14: FlushDeltaMemStoresOp(90beaa09e886496998fd6af32e1cc5a8) complete. Timing: real 0.042s	user 0.027s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18994,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.915354 10833 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:04.916040 10833 tablet_replica.cc:333] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14: stopping tablet replica
I20260812 06:19:04.916260 10833 raft_consensus.cc:2243] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:04.916499 10833 raft_consensus.cc:2272] T 90beaa09e886496998fd6af32e1cc5a8 P 39fc7e4391264dc68a01854bc800fd14 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:04.931425 10833 tablet_server.cc:196] TabletServer@127.10.148.65:0 shutdown complete.
I20260812 06:19:04.936206 10833 master.cc:562] Master@127.10.148.126:33683 shutting down...
I20260812 06:19:04.939358 10833 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:04.939533 10833 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:04.939603 10833 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6a9e05b849ce4afa9db08b60c77f48e4: stopping tablet replica
I20260812 06:19:04.952135 10833 master.cc:584] Master@127.10.148.126:33683 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5179 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:05.031553 10833 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.148.126:37523
I20260812 06:19:05.031977 10833 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.034505 11187 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:05.034641 11185 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.034727 10833 server_base.cc:1061] running on GCE node
W20260812 06:19:05.034602 11183 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.034997 10833 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.035040 10833 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:05.035054 10833 hybrid_clock.cc:648] HybridClock initialized: now 1786515545035054 us; error 0 us; skew 500 ppm
I20260812 06:19:05.035897 10833 webserver.cc:533] Webserver started at http://127.10.148.126:43651/ using document root <none> and password file <none>
I20260812 06:19:05.036065 10833 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.036115 10833 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.036197 10833 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.036618 10833 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/master-0-root/instance:
uuid: "4b6b85a0f090446eacba896570d48534"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-lkx2"
I20260812 06:19:05.038194 10833 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:05.039294 11196 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.039520 10833 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:05.039598 10833 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/master-0-root
uuid: "4b6b85a0f090446eacba896570d48534"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-lkx2"
I20260812 06:19:05.039674 10833 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:05.050127 10833 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.050527 10833 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.054656 10833 rpc_server.cc:307] RPC server started. Bound to: 127.10.148.126:37523
I20260812 06:19:05.070287 11291 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.148.126:37523 every 8 connection(s)
I20260812 06:19:05.070880 11292 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:05.073180 11292 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534: Bootstrap starting.
I20260812 06:19:05.074088 11292 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.075160 11292 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534: No bootstrap required, opened a new log
I20260812 06:19:05.075580 11292 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b6b85a0f090446eacba896570d48534" member_type: VOTER }
I20260812 06:19:05.075667 11292 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.075690 11292 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4b6b85a0f090446eacba896570d48534, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.075839 11292 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [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: "4b6b85a0f090446eacba896570d48534" member_type: VOTER }
I20260812 06:19:05.075927 11292 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.075965 11292 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.076016 11292 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.076740 11292 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b6b85a0f090446eacba896570d48534" member_type: VOTER }
I20260812 06:19:05.076902 11292 leader_election.cc:304] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [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: 4b6b85a0f090446eacba896570d48534; no voters: 
I20260812 06:19:05.077066 11292 leader_election.cc:290] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.077210 11300 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.077442 11300 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 1 LEADER]: Becoming Leader. State: Replica: 4b6b85a0f090446eacba896570d48534, State: Running, Role: LEADER
I20260812 06:19:05.077577 11292 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:05.077590 11300 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [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: "4b6b85a0f090446eacba896570d48534" member_type: VOTER }
I20260812 06:19:05.078105 11301 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4b6b85a0f090446eacba896570d48534" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b6b85a0f090446eacba896570d48534" member_type: VOTER } }
I20260812 06:19:05.078204 11301 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.078159 11306 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4b6b85a0f090446eacba896570d48534. Latest consensus state: current_term: 1 leader_uuid: "4b6b85a0f090446eacba896570d48534" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b6b85a0f090446eacba896570d48534" member_type: VOTER } }
I20260812 06:19:05.078248 11306 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.078460 11310 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:05.079298 11310 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:05.079457 10833 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:05.081182 11310 catalog_manager.cc:1383] Generated new cluster ID: 5874c66f607d4a448274f532cd4e82a0
I20260812 06:19:05.081239 11310 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:05.096740 11310 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:05.097384 11310 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:05.111119 11310 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534: Generated new TSK 0
I20260812 06:19:05.111354 11310 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:05.144201 10833 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.146327 11333 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.146452 10833 server_base.cc:1061] running on GCE node
W20260812 06:19:05.146391 11343 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:05.146423 11332 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.146755 10833 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.146806 10833 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:05.146822 10833 hybrid_clock.cc:648] HybridClock initialized: now 1786515545146822 us; error 0 us; skew 500 ppm
I20260812 06:19:05.147708 10833 webserver.cc:533] Webserver started at http://127.10.148.65:45173/ using document root <none> and password file <none>
I20260812 06:19:05.147881 10833 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.147931 10833 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.148011 10833 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.148473 10833 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/instance:
uuid: "2d125c35a5364b8e834e4f59c766cf57"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-lkx2"
I20260812 06:19:05.150017 10833 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:05.151088 11352 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.151381 10833 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:05.151463 10833 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root
uuid: "2d125c35a5364b8e834e4f59c766cf57"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-lkx2"
I20260812 06:19:05.151542 10833 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:05.160547 10833 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.160976 10833 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.161302 10833 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:05.161808 10833 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:05.161847 10833 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.161895 10833 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:05.161919 10833 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.165941 10833 rpc_server.cc:307] RPC server started. Bound to: 127.10.148.65:40315
I20260812 06:19:05.165994 11464 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.148.65:40315 every 8 connection(s)
I20260812 06:19:05.174516 11466 heartbeater.cc:344] Connected to a master server at 127.10.148.126:37523
I20260812 06:19:05.174650 11466 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:05.174938 11466 heartbeater.cc:507] Master 127.10.148.126:37523 requested a full tablet report, sending...
I20260812 06:19:05.175671 11230 ts_manager.cc:194] Registered new tserver with Master: 2d125c35a5364b8e834e4f59c766cf57 (127.10.148.65:40315)
I20260812 06:19:05.176405 10833 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010041908s
I20260812 06:19:05.176586 11230 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41460
I20260812 06:19:05.183683 11230 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41470:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:05.192533 11401 tablet_service.cc:1511] Processing CreateTablet for tablet 4ed0d9fc03c44cba998c0ef70a719536 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8d6b65d5225f445ea5e8a88913923057]), partition=
I20260812 06:19:05.192811 11401 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4ed0d9fc03c44cba998c0ef70a719536. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:05.194875 11491 tablet_bootstrap.cc:492] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Bootstrap starting.
I20260812 06:19:05.195801 11491 tablet_bootstrap.cc:654] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.196978 11491 tablet_bootstrap.cc:492] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: No bootstrap required, opened a new log
I20260812 06:19:05.197074 11491 ts_tablet_manager.cc:1403] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:05.197551 11491 raft_consensus.cc:359] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d125c35a5364b8e834e4f59c766cf57" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 40315 } }
I20260812 06:19:05.197655 11491 raft_consensus.cc:385] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.197687 11491 raft_consensus.cc:740] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2d125c35a5364b8e834e4f59c766cf57, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.197844 11491 consensus_queue.cc:260] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [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: "2d125c35a5364b8e834e4f59c766cf57" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 40315 } }
I20260812 06:19:05.197942 11491 raft_consensus.cc:399] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.197985 11491 raft_consensus.cc:493] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.198031 11491 raft_consensus.cc:3060] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.198853 11491 raft_consensus.cc:515] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d125c35a5364b8e834e4f59c766cf57" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 40315 } }
I20260812 06:19:05.198983 11491 leader_election.cc:304] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [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: 2d125c35a5364b8e834e4f59c766cf57; no voters: 
I20260812 06:19:05.199157 11491 leader_election.cc:290] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.199288 11493 raft_consensus.cc:2804] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.199465 11491 ts_tablet_manager.cc:1434] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:05.199487 11493 raft_consensus.cc:697] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 1 LEADER]: Becoming Leader. State: Replica: 2d125c35a5364b8e834e4f59c766cf57, State: Running, Role: LEADER
I20260812 06:19:05.199493 11466 heartbeater.cc:499] Master 127.10.148.126:37523 was elected leader, sending a full tablet report...
I20260812 06:19:05.199693 11493 consensus_queue.cc:237] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [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: "2d125c35a5364b8e834e4f59c766cf57" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 40315 } }
I20260812 06:19:05.201121 11230 catalog_manager.cc:5719] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2d125c35a5364b8e834e4f59c766cf57 (127.10.148.65). New cstate: current_term: 1 leader_uuid: "2d125c35a5364b8e834e4f59c766cf57" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d125c35a5364b8e834e4f59c766cf57" member_type: VOTER last_known_addr { host: "127.10.148.65" port: 40315 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:05.260489 10833 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:19:05.416960 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushMRSOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=19.054940
I20260812 06:19:05.561374 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushMRSOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.144s	user 0.111s	sys 0.032s Metrics: {"bytes_written":12471591,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":805,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34470,"lbm_writes_lt_1ms":771,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":3328,"update_count":1520}
I20260812 06:19:05.562042 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling LogGCOp(4ed0d9fc03c44cba998c0ef70a719536): free 20743880 bytes of WAL
I20260812 06:19:05.562255 11362 log_reader.cc:385] T 4ed0d9fc03c44cba998c0ef70a719536: removed 2 log segments from log reader
I20260812 06:19:05.562305 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000001 (ops 1-6)
I20260812 06:19:05.562345 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000002 (ops 7-11)
I20260812 06:19:05.566301 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: LogGCOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:05.566722 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:05.585794 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.019s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3663,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:05.586268 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling UndoDeltaBlockGCOp(4ed0d9fc03c44cba998c0ef70a719536): 16821648 bytes on disk
I20260812 06:19:05.586688 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: UndoDeltaBlockGCOp(4ed0d9fc03c44cba998c0ef70a719536) 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:19:05.587229 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:05.601689 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4956,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:05.602520 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:05.750138 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.147s	user 0.114s	sys 0.033s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405550,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":512,"lbm_read_time_us":10899,"lbm_reads_lt_1ms":559,"lbm_write_time_us":25754,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":334,"threads_started":5,"update_count":2450}
I20260812 06:19:05.750701 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:05.799424 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.049s	user 0.013s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21008,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.799896 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:05.812500 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.813006 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:05.972599 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.159s	user 0.109s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":278,"lbm_read_time_us":12662,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27144,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":33920,"update_count":2500}
I20260812 06:19:05.973265 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:06.021420 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.048s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":19115,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.022002 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:06.178939 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.157s	user 0.121s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":315,"lbm_read_time_us":11831,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26283,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.179790 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:06.224391 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.044s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18028,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.224875 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:06.236203 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.236893 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:06.410224 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.173s	user 0.105s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":11257,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25564,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:19:06.410833 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=11.118625
I20260812 06:19:06.449561 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.039s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16805,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:06.450114 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:06.463861 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4753,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:06.464418 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:06.593463 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.129s	user 0.102s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":9079,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25078,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:06.594102 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=10.126437
I20260812 06:19:06.632021 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.038s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16266,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.632674 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:06.645190 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.645728 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:06.781788 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.136s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":611,"lbm_read_time_us":8966,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26989,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2000}
I20260812 06:19:06.782459 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=10.126437
I20260812 06:19:06.826756 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.044s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16201,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.827241 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:06.839599 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.840716 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushMRSOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:06.873667 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushMRSOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1321,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1629,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:06.874287 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling LogGCOp(4ed0d9fc03c44cba998c0ef70a719536): free 121006437 bytes of WAL
I20260812 06:19:06.874519 11362 log_reader.cc:385] T 4ed0d9fc03c44cba998c0ef70a719536: removed 12 log segments from log reader
I20260812 06:19:06.874567 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000003 (ops 12-16)
I20260812 06:19:06.874595 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000004 (ops 17-21)
I20260812 06:19:06.874629 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000005 (ops 22-26)
I20260812 06:19:06.874663 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000006 (ops 27-31)
I20260812 06:19:06.874694 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000007 (ops 32-36)
I20260812 06:19:06.874727 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000008 (ops 37-41)
I20260812 06:19:06.874758 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000009 (ops 42-46)
I20260812 06:19:06.874789 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000010 (ops 47-50)
I20260812 06:19:06.874820 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000011 (ops 51-55)
I20260812 06:19:06.874851 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000012 (ops 56-60)
I20260812 06:19:06.874890 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000013 (ops 61-65)
I20260812 06:19:06.874922 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000014 (ops 66-70)
I20260812 06:19:06.897523 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: LogGCOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:06.897957 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling UndoDeltaBlockGCOp(4ed0d9fc03c44cba998c0ef70a719536): 472 bytes on disk
I20260812 06:19:06.898532 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: UndoDeltaBlockGCOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:06.899025 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=3.181125
I20260812 06:19:06.910848 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4108,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:06.911362 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:06.926331 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5361,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:06.927048 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:07.098456 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.171s	user 0.132s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":841,"lbm_read_time_us":12682,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34159,"lbm_writes_lt_1ms":643,"mutex_wait_us":642,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:07.099040 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:07.149122 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.050s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23459,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.149799 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:07.166474 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.166992 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:07.330884 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.164s	user 0.120s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1609,"lbm_read_time_us":11552,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29566,"lbm_writes_lt_1ms":543,"mutex_wait_us":550,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:07.331423 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:07.396811 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.065s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22392,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.397368 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:07.408389 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.409161 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:07.569610 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.160s	user 0.084s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":841,"lbm_read_time_us":11618,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27251,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:07.570278 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:07.627774 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.057s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23660,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.628444 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:07.639569 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.640213 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:07.805182 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.165s	user 0.116s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":7062,"dirs.run_cpu_time_us":963,"dirs.run_wall_time_us":7513,"lbm_read_time_us":11986,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26868,"lbm_writes_lt_1ms":543,"mutex_wait_us":3625,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:19:07.805708 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:07.863994 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.058s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21945,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.864710 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:07.875212 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3901,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.875762 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:08.078251 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.202s	user 0.112s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":14410,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29042,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31360,"update_count":2500}
I20260812 06:19:08.079526 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:08.136837 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.057s	user 0.048s	sys 0.006s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27159,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.137378 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:08.162851 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.025s	user 0.005s	sys 0.017s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6307,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.163396 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:08.339123 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.176s	user 0.091s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":300,"lbm_read_time_us":13250,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27532,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:19:08.340241 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:08.381760 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.041s	user 0.019s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17735,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.382369 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:08.398379 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6513,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.398939 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushMRSOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:08.433343 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushMRSOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.034s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1398,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1555,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:08.434231 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling LogGCOp(4ed0d9fc03c44cba998c0ef70a719536): free 136728255 bytes of WAL
I20260812 06:19:08.434504 11362 log_reader.cc:385] T 4ed0d9fc03c44cba998c0ef70a719536: removed 13 log segments from log reader
I20260812 06:19:08.434556 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000015 (ops 71-75)
I20260812 06:19:08.434597 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000016 (ops 76-80)
I20260812 06:19:08.434631 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000017 (ops 81-85)
I20260812 06:19:08.434656 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000018 (ops 86-90)
I20260812 06:19:08.434687 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000019 (ops 91-95)
I20260812 06:19:08.434729 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000020 (ops 96-100)
I20260812 06:19:08.434762 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000021 (ops 101-105)
I20260812 06:19:08.434790 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000022 (ops 106-110)
I20260812 06:19:08.434821 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000023 (ops 111-115)
I20260812 06:19:08.434859 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000024 (ops 116-120)
I20260812 06:19:08.434890 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000025 (ops 121-125)
I20260812 06:19:08.434921 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000026 (ops 126-130)
I20260812 06:19:08.434952 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000027 (ops 131-135)
I20260812 06:19:08.463151 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: LogGCOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:08.463641 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling UndoDeltaBlockGCOp(4ed0d9fc03c44cba998c0ef70a719536): 493 bytes on disk
I20260812 06:19:08.464211 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: UndoDeltaBlockGCOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:19:08.464839 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=3.181125
I20260812 06:19:08.483994 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6694,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:08.484558 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:08.493985 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3282,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:08.494438 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:08.733263 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.239s	user 0.165s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2718,"lbm_read_time_us":14609,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37624,"lbm_writes_lt_1ms":743,"mutex_wait_us":91,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:19:08.733892 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=18.063937
I20260812 06:19:08.798521 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.064s	user 0.027s	sys 0.033s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28041,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:08.799068 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:08.810190 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.810770 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:09.028811 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.218s	user 0.161s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2673,"lbm_read_time_us":13946,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38439,"lbm_writes_lt_1ms":643,"mutex_wait_us":731,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:19:09.030104 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=15.087375
I20260812 06:19:09.090127 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.060s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":25361,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:09.090757 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:09.111625 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.021s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4078,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.112185 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:09.126406 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4957,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:09.127051 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:09.326578 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.199s	user 0.136s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":180,"lbm_read_time_us":13620,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32958,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:19:09.327211 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=15.087375
I20260812 06:19:09.373406 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.043s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":18274,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:09.373955 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:09.395627 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.021s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.396102 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:09.405396 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3288,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:09.405864 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:09.609990 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.204s	user 0.146s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":121,"lbm_read_time_us":12582,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35445,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:19:09.610625 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:09.654348 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.042s	user 0.019s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18492,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.654959 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:09.667388 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.667886 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:09.832989 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.165s	user 0.129s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":10979,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28714,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":95488,"update_count":2500}
I20260812 06:19:09.833668 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=14.095187
I20260812 06:19:09.882407 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.049s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19416,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.883067 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:09.899308 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.899839 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushMRSOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:09.929037 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushMRSOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.029s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1451,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:09.929719 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling LogGCOp(4ed0d9fc03c44cba998c0ef70a719536): free 120553636 bytes of WAL
I20260812 06:19:09.929949 11362 log_reader.cc:385] T 4ed0d9fc03c44cba998c0ef70a719536: removed 12 log segments from log reader
I20260812 06:19:09.930001 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000028 (ops 136-140)
I20260812 06:19:09.930032 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000029 (ops 141-144)
I20260812 06:19:09.930063 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000030 (ops 145-149)
I20260812 06:19:09.930095 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000031 (ops 150-154)
I20260812 06:19:09.930122 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000032 (ops 155-159)
I20260812 06:19:09.930153 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000033 (ops 160-164)
I20260812 06:19:09.930182 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000034 (ops 165-168)
I20260812 06:19:09.930215 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000035 (ops 169-173)
I20260812 06:19:09.930248 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000036 (ops 174-178)
I20260812 06:19:09.930279 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000037 (ops 179-183)
I20260812 06:19:09.930310 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000038 (ops 184-188)
I20260812 06:19:09.930341 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000039 (ops 189-193)
I20260812 06:19:09.952490 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: LogGCOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.023s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:09.952940 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:09.975255 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.022s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.975728 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling LogGCOp(4ed0d9fc03c44cba998c0ef70a719536): free 12017954 bytes of WAL
I20260812 06:19:09.975934 11362 log_reader.cc:385] T 4ed0d9fc03c44cba998c0ef70a719536: removed 1 log segments from log reader
I20260812 06:19:09.975979 11362 log.cc:1079] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: Deleting log segment in path: /tmp/dist-test-tasksOrbam/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515539841910-10833-0/minicluster-data/ts-0-root/wals/4ed0d9fc03c44cba998c0ef70a719536/wal-000000040 (ops 194-198)
I20260812 06:19:09.978104 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: LogGCOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:09.978425 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=2.188937
I20260812 06:19:09.988675 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: FlushDeltaMemStoresOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.989138 11469 maintenance_manager.cc:419] P 2d125c35a5364b8e834e4f59c766cf57: Scheduling MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536): perf score=1.000000
I20260812 06:19:10.019482 10833 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.759s	user 1.696s	sys 0.157s
I20260812 06:19:10.104126 10833 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.001s	sys 0.000s
I20260812 06:19:10.104667 10833 tablet_server.cc:179] TabletServer@127.10.148.65:0 shutting down...
I20260812 06:19:10.183056 11362 maintenance_manager.cc:643] P 2d125c35a5364b8e834e4f59c766cf57: MajorDeltaCompactionOp(4ed0d9fc03c44cba998c0ef70a719536) complete. Timing: real 0.194s	user 0.130s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":256,"lbm_read_time_us":14649,"lbm_reads_lt_1ms":770,"lbm_write_time_us":31679,"lbm_writes_lt_1ms":743,"mutex_wait_us":61,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":28416,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:19:10.184367 10833 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:10.184760 10833 tablet_replica.cc:333] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57: stopping tablet replica
I20260812 06:19:10.184927 10833 raft_consensus.cc:2243] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.185137 10833 raft_consensus.cc:2272] T 4ed0d9fc03c44cba998c0ef70a719536 P 2d125c35a5364b8e834e4f59c766cf57 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.190205 10833 tablet_server.cc:196] TabletServer@127.10.148.65:0 shutdown complete.
I20260812 06:19:10.240036 10833 master.cc:562] Master@127.10.148.126:37523 shutting down...
I20260812 06:19:10.243218 10833 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.243395 10833 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.243448 10833 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4b6b85a0f090446eacba896570d48534: stopping tablet replica
I20260812 06:19:10.255839 10833 master.cc:584] Master@127.10.148.126:37523 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5299 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10480 ms total)

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