Actions
Bug #21254
closed
keep-balance TestRunForever is racey
Status:
Resolved
Priority:
Normal
Assigned To:
Category:
Tests
Target version:
Story points:
-
Release:
Release relationship:
Auto
Description
---------------------------------------------------------------------- FAIL: balance_run_test.go:626: runSuite.TestRunForever time="2023-12-01T16:12:59.498333882Z" level=info msg="acquiring service lock" time="2023-12-01T16:12:59.502981282Z" level=info msg="starting up: will scan every 1ms and on SIGUSR1" time="2023-12-01T16:12:59.503086322Z" level=info msg="acquiring active lock" time="2023-12-01T16:12:59.507383962Z" level=info msg="sweep: start" time="2023-12-01T16:12:59.507475162Z" level=info msg="skipping zzzzz-bi6l4-h0a0xwut9qa6g3a with service type \"proxy\"" time="2023-12-01T16:12:59.507625422Z" level=info msg="clearing existing trash lists, in case the new rendezvous order differs from previous run" time="2023-12-01T16:12:59.507637742Z" level=info msg="send_trash_lists: start" time="2023-12-01T16:12:59.507729922Z" level=info msg="send_trash_lists: took 8.984e-05s" time="2023-12-01T16:12:59.507745142Z" level=info msg="get_state: start" time="2023-12-01T16:12:59.507796493Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.507822133Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.507829242Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.507830262Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.507834573Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.507849442Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.507857102Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.507884102Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.507890993Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.507902693Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.507911482Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): add 2 entries to map" time="2023-12-01T16:12:59.507919333Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): added 2 entries to map at 1x (2 replicas)" time="2023-12-01T16:12:59.507925093Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.507940293Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.507946173Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.507958922Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.508212042Z" level=info msg="heap 4661248 stack 819200 heapalloc 2625568 virt 1351573504 res 27389952" time="2023-12-01T16:12:59.514064253Z" level=info msg="collections: 293/3" time="2023-12-01T16:12:59.514127573Z" level=info msg="get_state: took 0.0063806s" time="2023-12-01T16:12:59.514141513Z" level=info msg="changeset_compute: start" time="2023-12-01T16:12:59.514189002Z" level=info msg="6a4ff0499484c6c79c95cd8c566bd25f+249025 refs=3 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.514199333Z" level=info msg="cdd549ae79fe6640fa3d5c6261d8303c+195 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.514221902Z" level=info msg="d21353cfe035e3e384563ee55eadbb2f+67108864 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.514210302Z" level=info msg="acbd18db4cc2f85cedef654fccc4a4d8+3 refs=6 needed=2 unneeded=2 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=stay,12345679000000000 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=stay,12345680000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=trash,12345681000000000 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=trash,12345682000000000]" time="2023-12-01T16:12:59.514251633Z" level=info msg="5c77a43e329b9838cbec18ff42790e57+55605760 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.514269542Z" level=info msg="92b53930db60fe94be2a73fc771ba921+34 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.514271222Z" level=info msg="85877ca2d7e05498dd3d109baf2df106+95 refs=5 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.514284993Z" level=info msg="56ac2557b1ded11ccab7293dc47d1e88+44 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.514290202Z" level=info msg="4c6c2c0ac8aa0696edd7316a3be5ca3c+5 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.514223253Z" level=info msg="73feffa4b7f6bb68e44cf984c85f6e88+3 refs=220 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.514209942Z" level=info msg="8c12f5f5297b7337598170c6f531fcee+7882 refs=14 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.514305693Z" level=info msg="fca529cfe035e3e384563ee55eadbb2f+67108863 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.514313813Z" level=info msg="8258b505536a9ab47baa2f4281cb932a+9 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.514321362Z" level=info msg="37b51d194a7513e45b56f6524f2d51f2+3 refs=32 needed=1 unneeded=0 pulling=2 map[archive:2 default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=pull,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=pull,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=stay,12345678000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.514326713Z" level=info msg="4d20280d5e516a0109768d49ab0f3318+3 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.514330233Z" level=info msg="f0ef7081e1539ac00ef5b761b4fb01b3+12 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.514335482Z" level=info msg="3858f62230ac3c915f300c664312c63f+6 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.514338202Z" level=info msg="29d7797f1888013986899bc9083783fa+3 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.514342042Z" level=info msg="2bbc341c702df4d8f42ec31f16c10120+64 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.514683662Z" level=info msg="changeset_compute: took 0.000539369s" time="2023-12-01T16:12:59.514692353Z" level=info msg="===" time="2023-12-01T16:12:59.514698422Z" level=info msg="17 replicas (17 blocks, 190080867 bytes) lost (0=have<want)" time="2023-12-01T16:12:59.514706073Z" level=info msg="2 replicas (1 blocks, 6 bytes) underreplicated (0<have<want)" time="2023-12-01T16:12:59.514710593Z" level=info msg="0 replicas (0 blocks, 0 bytes) just right (have=want)" time="2023-12-01T16:12:59.514715222Z" level=info msg="2 replicas (1 blocks, 6 bytes) overreplicated (have>want>0)" time="2023-12-01T16:12:59.514721122Z" level=info msg="0 replicas (0 blocks, 0 bytes) unreferenced (have>want=0, new)" time="2023-12-01T16:12:59.514725362Z" level=info msg="0 replicas (0 blocks, 0 bytes) garbage (have>want=0, old)" time="2023-12-01T16:12:59.514730442Z" level=info msg="===" time="2023-12-01T16:12:59.514734493Z" level=info msg="storage class \"default\": 3 replicas (2 blocks, 9 bytes) needed" time="2023-12-01T16:12:59.514739322Z" level=info msg="storage class \"default\": 2 replicas (1 blocks, 6 bytes) unneeded" time="2023-12-01T16:12:59.514782713Z" level=info msg="storage class \"default\": 2 replicas (1 blocks, 6 bytes) pulling" time="2023-12-01T16:12:59.514791513Z" level=info msg="storage class \"default\": 17 replicas (17 blocks, 190080867 bytes) unachievable" time="2023-12-01T16:12:59.514800293Z" level=info msg="===" time="2023-12-01T16:12:59.514829133Z" level=info msg="3 replicas (2 blocks, 9 bytes) total commitment (excluding unreferenced)" time="2023-12-01T16:12:59.514834082Z" level=info msg="5 replicas (2 blocks, 15 bytes) total usage" time="2023-12-01T16:12:59.514858253Z" level=info msg="===" time="2023-12-01T16:12:59.514959933Z" level=info msg="zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:1, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.514968222Z" level=info msg="zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.514973722Z" level=info msg="zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:1, Trashes:0} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.514978553Z" level=info msg="zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:0} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.514982962Z" level=info msg="===" time="2023-12-01T16:12:59.514985633Z" level=info msg="Replication level distribution:" time="2023-12-01T16:12:59.514990593Z" level=info msg=" 0: 17 #########################################################" time="2023-12-01T16:12:59.514994413Z" level=info msg=" 1: 1 #############" time="2023-12-01T16:12:59.514997342Z" level=info msg=" 2: 0 " time="2023-12-01T16:12:59.514999993Z" level=info msg=" 3: 0 " time="2023-12-01T16:12:59.515002562Z" level=info msg=" 4: 1 #############" time="2023-12-01T16:12:59.515005222Z" level=info msg="===" time="2023-12-01T16:12:59.515025393Z" level=info msg="send_pull_lists: start" time="2023-12-01T16:12:59.515166082Z" level=info msg="send_pull_lists: took 0.000139s" time="2023-12-01T16:12:59.515172582Z" level=info msg="send_trash_lists: start" time="2023-12-01T16:12:59.515234313Z" level=info msg="send_trash_lists: took 5.988e-05s" time="2023-12-01T16:12:59.515242473Z" level=info msg="sweep: took 0.007859451s" time="2023-12-01T16:12:59.515501482Z" level=info msg="run succeeded" time="2023-12-01T16:12:59.515508373Z" level=info msg="timer went off" time="2023-12-01T16:12:59.515511433Z" level=info msg="starting next run" time="2023-12-01T16:12:59.515635593Z" level=info msg="acquiring active lock" time="2023-12-01T16:12:59.515836793Z" level=info msg="sweep: start" time="2023-12-01T16:12:59.515933702Z" level=info msg="skipping zzzzz-bi6l4-h0a0xwut9qa6g3a with service type \"proxy\"" time="2023-12-01T16:12:59.516119113Z" level=info msg="get_state: start" time="2023-12-01T16:12:59.516160882Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.516171413Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.516179342Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.516216013Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.516225282Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.516230753Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.516244882Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.516245193Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.516256273Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.516262133Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.516267373Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): add 2 entries to map" time="2023-12-01T16:12:59.516189942Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.516278862Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): added 2 entries to map at 1x (2 replicas)" time="2023-12-01T16:12:59.516282722Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.516284182Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.516288142Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.516477893Z" level=info msg="heap 4546560 stack 884736 heapalloc 1973688 virt 1351573504 res 27389952" time="2023-12-01T16:12:59.517448562Z" level=info msg="collections: 293/3" time="2023-12-01T16:12:59.517532872Z" level=info msg="get_state: took 0.001412309s" time="2023-12-01T16:12:59.517541252Z" level=info msg="changeset_compute: start" time="2023-12-01T16:12:59.517568562Z" level=info msg="fca529cfe035e3e384563ee55eadbb2f+67108863 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.517585382Z" level=info msg="3858f62230ac3c915f300c664312c63f+6 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.517593472Z" level=info msg="92b53930db60fe94be2a73fc771ba921+34 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.517600572Z" level=info msg="d21353cfe035e3e384563ee55eadbb2f+67108864 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.517615362Z" level=info msg="8258b505536a9ab47baa2f4281cb932a+9 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.517614712Z" level=info msg="5c77a43e329b9838cbec18ff42790e57+55605760 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.517616812Z" level=info msg="8c12f5f5297b7337598170c6f531fcee+7882 refs=14 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.517626732Z" level=info msg="37b51d194a7513e45b56f6524f2d51f2+3 refs=32 needed=1 unneeded=0 pulling=2 map[archive:2 default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=pull,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=pull,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=stay,12345678000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.517638882Z" level=info msg="cdd549ae79fe6640fa3d5c6261d8303c+195 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.517640462Z" level=info msg="85877ca2d7e05498dd3d109baf2df106+95 refs=5 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.517654152Z" level=info msg="29d7797f1888013986899bc9083783fa+3 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.517665272Z" level=info msg="73feffa4b7f6bb68e44cf984c85f6e88+3 refs=220 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.517669182Z" level=info msg="4c6c2c0ac8aa0696edd7316a3be5ca3c+5 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.517689642Z" level=info msg="4d20280d5e516a0109768d49ab0f3318+3 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.517706072Z" level=info msg="f0ef7081e1539ac00ef5b761b4fb01b3+12 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.517651682Z" level=info msg="2bbc341c702df4d8f42ec31f16c10120+64 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.517725842Z" level=info msg="56ac2557b1ded11ccab7293dc47d1e88+44 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.517742982Z" level=info msg="6a4ff0499484c6c79c95cd8c566bd25f+249025 refs=3 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.517631432Z" level=info msg="acbd18db4cc2f85cedef654fccc4a4d8+3 refs=6 needed=2 unneeded=2 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=stay,12345684000000000 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=stay,12345686000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=trash,12345683000000000 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=trash,12345685000000000]" time="2023-12-01T16:12:59.517762262Z" level=info msg="changeset_compute: took 0.00022006s" time="2023-12-01T16:12:59.517765712Z" level=info msg="===" time="2023-12-01T16:12:59.517769722Z" level=info msg="17 replicas (17 blocks, 190080867 bytes) lost (0=have<want)" time="2023-12-01T16:12:59.517773412Z" level=info msg="2 replicas (1 blocks, 6 bytes) underreplicated (0<have<want)" time="2023-12-01T16:12:59.517776842Z" level=info msg="0 replicas (0 blocks, 0 bytes) just right (have=want)" time="2023-12-01T16:12:59.517780112Z" level=info msg="2 replicas (1 blocks, 6 bytes) overreplicated (have>want>0)" time="2023-12-01T16:12:59.517783602Z" level=info msg="0 replicas (0 blocks, 0 bytes) unreferenced (have>want=0, new)" time="2023-12-01T16:12:59.517787062Z" level=info msg="0 replicas (0 blocks, 0 bytes) garbage (have>want=0, old)" time="2023-12-01T16:12:59.517790202Z" level=info msg="===" time="2023-12-01T16:12:59.517793212Z" level=info msg="storage class \"default\": 3 replicas (2 blocks, 9 bytes) needed" time="2023-12-01T16:12:59.517796972Z" level=info msg="storage class \"default\": 2 replicas (1 blocks, 6 bytes) unneeded" time="2023-12-01T16:12:59.517800542Z" level=info msg="storage class \"default\": 2 replicas (1 blocks, 6 bytes) pulling" time="2023-12-01T16:12:59.517805492Z" level=info msg="storage class \"default\": 17 replicas (17 blocks, 190080867 bytes) unachievable" time="2023-12-01T16:12:59.517809062Z" level=info msg="===" time="2023-12-01T16:12:59.517812032Z" level=info msg="3 replicas (2 blocks, 9 bytes) total commitment (excluding unreferenced)" time="2023-12-01T16:12:59.517815532Z" level=info msg="5 replicas (2 blocks, 15 bytes) total usage" time="2023-12-01T16:12:59.517818162Z" level=info msg="===" time="2023-12-01T16:12:59.517822582Z" level=info msg="zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:0} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.517827982Z" level=info msg="zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:1, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.517832552Z" level=info msg="zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.517836992Z" level=info msg="zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:1, Trashes:0} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.517840612Z" level=info msg="===" time="2023-12-01T16:12:59.517842902Z" level=info msg="Replication level distribution:" time="2023-12-01T16:12:59.517846742Z" level=info msg=" 0: 17 #########################################################" time="2023-12-01T16:12:59.517850042Z" level=info msg=" 1: 1 #############" time="2023-12-01T16:12:59.517852792Z" level=info msg=" 2: 0 " time="2023-12-01T16:12:59.517855652Z" level=info msg=" 3: 0 " time="2023-12-01T16:12:59.517858212Z" level=info msg=" 4: 1 #############" time="2023-12-01T16:12:59.517860772Z" level=info msg="===" time="2023-12-01T16:12:59.517865402Z" level=info msg="send_pull_lists: start" time="2023-12-01T16:12:59.518002292Z" level=info msg="send_pull_lists: took 0.00013474s" time="2023-12-01T16:12:59.518008792Z" level=info msg="send_trash_lists: start" time="2023-12-01T16:12:59.518101202Z" level=info msg="send_trash_lists: took 9.066e-05s" time="2023-12-01T16:12:59.518109222Z" level=info msg="sweep: took 0.00227284s" time="2023-12-01T16:12:59.518311382Z" level=info msg="run succeeded" time="2023-12-01T16:12:59.518318042Z" level=info msg="timer went off" time="2023-12-01T16:12:59.518320962Z" level=info msg="starting next run" time="2023-12-01T16:12:59.518421472Z" level=info msg="acquiring active lock" time="2023-12-01T16:12:59.518587102Z" level=info msg="sweep: start" time="2023-12-01T16:12:59.518649982Z" level=info msg="skipping zzzzz-bi6l4-h0a0xwut9qa6g3a with service type \"proxy\"" time="2023-12-01T16:12:59.518822812Z" level=info msg="get_state: start" time="2023-12-01T16:12:59.518856252Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.518884662Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.518881742Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.518887412Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.518891062Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.518911532Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.518923712Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.518978952Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.518925882Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.518986222Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.518992072Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.518990552Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.518997912Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.518952702Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): add 2 entries to map" time="2023-12-01T16:12:59.519008902Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): added 2 entries to map at 1x (2 replicas)" time="2023-12-01T16:12:59.519014052Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.519564142Z" level=info msg="heap 5275648 stack 917504 heapalloc 3221856 virt 1351573504 res 27709440" time="2023-12-01T16:12:59.520756652Z" level=info msg="collections: 293/3" time="2023-12-01T16:12:59.520817022Z" level=info msg="get_state: took 0.00199287s" time="2023-12-01T16:12:59.520825302Z" level=info msg="changeset_compute: start" time="2023-12-01T16:12:59.520865362Z" level=info msg="d21353cfe035e3e384563ee55eadbb2f+67108864 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.520883202Z" level=info msg="3858f62230ac3c915f300c664312c63f+6 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.520883442Z" level=info msg="92b53930db60fe94be2a73fc771ba921+34 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.520889962Z" level=info msg="85877ca2d7e05498dd3d109baf2df106+95 refs=5 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.520906492Z" level=info msg="acbd18db4cc2f85cedef654fccc4a4d8+3 refs=6 needed=2 unneeded=2 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=stay,12345687000000000 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=stay,12345689000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=trash,12345688000000000 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=trash,12345690000000000]" time="2023-12-01T16:12:59.520913472Z" level=info msg="4d20280d5e516a0109768d49ab0f3318+3 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.520912932Z" level=info msg="73feffa4b7f6bb68e44cf984c85f6e88+3 refs=220 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.520922662Z" level=info msg="5c77a43e329b9838cbec18ff42790e57+55605760 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.520935102Z" level=info msg="cdd549ae79fe6640fa3d5c6261d8303c+195 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.520937522Z" level=info msg="6a4ff0499484c6c79c95cd8c566bd25f+249025 refs=3 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.520937382Z" level=info msg="2bbc341c702df4d8f42ec31f16c10120+64 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.520949992Z" level=info msg="56ac2557b1ded11ccab7293dc47d1e88+44 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.520955222Z" level=info msg="4c6c2c0ac8aa0696edd7316a3be5ca3c+5 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.520956862Z" level=info msg="37b51d194a7513e45b56f6524f2d51f2+3 refs=32 needed=1 unneeded=0 pulling=2 map[archive:2 default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=pull,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=pull,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=stay,12345678000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.520965152Z" level=info msg="f0ef7081e1539ac00ef5b761b4fb01b3+12 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.520972722Z" level=info msg="8c12f5f5297b7337598170c6f531fcee+7882 refs=14 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.520975652Z" level=info msg="fca529cfe035e3e384563ee55eadbb2f+67108863 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.520980342Z" level=info msg="29d7797f1888013986899bc9083783fa+3 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.520987042Z" level=info msg="8258b505536a9ab47baa2f4281cb932a+9 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.521000932Z" level=info msg="changeset_compute: took 0.00017429s" time="2023-12-01T16:12:59.521004112Z" level=info msg="===" time="2023-12-01T16:12:59.521008162Z" level=info msg="17 replicas (17 blocks, 190080867 bytes) lost (0=have<want)" time="2023-12-01T16:12:59.521012272Z" level=info msg="2 replicas (1 blocks, 6 bytes) underreplicated (0<have<want)" time="2023-12-01T16:12:59.521015922Z" level=info msg="0 replicas (0 blocks, 0 bytes) just right (have=want)" time="2023-12-01T16:12:59.521019332Z" level=info msg="2 replicas (1 blocks, 6 bytes) overreplicated (have>want>0)" time="2023-12-01T16:12:59.521022592Z" level=info msg="0 replicas (0 blocks, 0 bytes) unreferenced (have>want=0, new)" time="2023-12-01T16:12:59.521026082Z" level=info msg="0 replicas (0 blocks, 0 bytes) garbage (have>want=0, old)" time="2023-12-01T16:12:59.521028872Z" level=info msg="===" time="2023-12-01T16:12:59.521031762Z" level=info msg="storage class \"default\": 3 replicas (2 blocks, 9 bytes) needed" time="2023-12-01T16:12:59.521035342Z" level=info msg="storage class \"default\": 2 replicas (1 blocks, 6 bytes) unneeded" time="2023-12-01T16:12:59.521038842Z" level=info msg="storage class \"default\": 2 replicas (1 blocks, 6 bytes) pulling" time="2023-12-01T16:12:59.521042692Z" level=info msg="storage class \"default\": 17 replicas (17 blocks, 190080867 bytes) unachievable" time="2023-12-01T16:12:59.521046252Z" level=info msg="===" time="2023-12-01T16:12:59.521049122Z" level=info msg="3 replicas (2 blocks, 9 bytes) total commitment (excluding unreferenced)" time="2023-12-01T16:12:59.521052592Z" level=info msg="5 replicas (2 blocks, 15 bytes) total usage" time="2023-12-01T16:12:59.521055232Z" level=info msg="===" time="2023-12-01T16:12:59.521059932Z" level=info msg="zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:1, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.521066172Z" level=info msg="zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.521071332Z" level=info msg="zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:1, Trashes:0} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.521075862Z" level=info msg="zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:0} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.521079442Z" level=info msg="===" time="2023-12-01T16:12:59.521081822Z" level=info msg="Replication level distribution:" time="2023-12-01T16:12:59.521085512Z" level=info msg=" 0: 17 #########################################################" time="2023-12-01T16:12:59.521088952Z" level=info msg=" 1: 1 #############" time="2023-12-01T16:12:59.521091712Z" level=info msg=" 2: 0 " time="2023-12-01T16:12:59.521094252Z" level=info msg=" 3: 0 " time="2023-12-01T16:12:59.521096692Z" level=info msg=" 4: 1 #############" time="2023-12-01T16:12:59.521099072Z" level=info msg="===" time="2023-12-01T16:12:59.521104082Z" level=info msg="send_pull_lists: start" time="2023-12-01T16:12:59.521193802Z" level=info msg="send_pull_lists: took 8.868e-05s" time="2023-12-01T16:12:59.521198242Z" level=info msg="send_trash_lists: start" time="2023-12-01T16:12:59.521264842Z" level=info msg="send_trash_lists: took 6.614e-05s" time="2023-12-01T16:12:59.521273942Z" level=info msg="sweep: took 0.00268704s" time="2023-12-01T16:12:59.521496992Z" level=info msg="run succeeded" time="2023-12-01T16:12:59.521504212Z" level=info msg="timer went off" time="2023-12-01T16:12:59.521507452Z" level=info msg="starting next run" time="2023-12-01T16:12:59.521624372Z" level=info msg="acquiring active lock" time="2023-12-01T16:12:59.521841172Z" level=info msg="sweep: start" time="2023-12-01T16:12:59.521932212Z" level=info msg="skipping zzzzz-bi6l4-h0a0xwut9qa6g3a with service type \"proxy\"" time="2023-12-01T16:12:59.522134472Z" level=info msg="get_state: start" time="2023-12-01T16:12:59.522169912Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.522175752Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.522194322Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): add 2 entries to map" time="2023-12-01T16:12:59.522190932Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.522245152Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.522253042Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.522258842Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.522201142Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): added 2 entries to map at 1x (2 replicas)" time="2023-12-01T16:12:59.522271222Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.522212792Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.522281142Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.522286162Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.522213132Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.522309992Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.522315452Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.522320432Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.522434222Z" level=info msg="heap 5218304 stack 950272 heapalloc 2943912 virt 1351573504 res 27942912" time="2023-12-01T16:12:59.523451072Z" level=info msg="collections: 293/3" time="2023-12-01T16:12:59.523690373Z" level=info msg="get_state: took 0.00155289s" time="2023-12-01T16:12:59.523707862Z" level=info msg="changeset_compute: start" time="2023-12-01T16:12:59.523754473Z" level=info msg="3858f62230ac3c915f300c664312c63f+6 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.523782582Z" level=info msg="acbd18db4cc2f85cedef654fccc4a4d8+3 refs=6 needed=2 unneeded=2 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=stay,12345692000000000 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=stay,12345691000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=trash,12345693000000000 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=trash,12345694000000000]" time="2023-12-01T16:12:59.523804653Z" level=info msg="4d20280d5e516a0109768d49ab0f3318+3 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.523855242Z" level=info msg="cdd549ae79fe6640fa3d5c6261d8303c+195 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.523897682Z" level=info msg="8258b505536a9ab47baa2f4281cb932a+9 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.523892473Z" level=info msg="2bbc341c702df4d8f42ec31f16c10120+64 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.524004762Z" level=info msg="6a4ff0499484c6c79c95cd8c566bd25f+249025 refs=3 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.524004942Z" level=info msg="8c12f5f5297b7337598170c6f531fcee+7882 refs=14 needed=0 unneeded=0 pulling=0 map[default:2] 2023/12/01 16:13:02 [info] 57881#57881: *2561 client 127.0.0.1 closed keepalive connection 2023/12/01 16:13:02 [info] 57881#57881: *2493 client 127.0.0.1 closed keepalive connection [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.524008833Z" level=info msg="4c6c2c0ac8aa0696edd7316a3be5ca3c+5 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.524032382Z" level=info msg="29d7797f1888013986899bc9083783fa+3 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.524051853Z" level=info msg="f0ef7081e1539ac00ef5b761b4fb01b3+12 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.524111242Z" level=info msg="92b53930db60fe94be2a73fc771ba921+34 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.524111822Z" level=info msg="fca529cfe035e3e384563ee55eadbb2f+67108863 refs=1 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.524032413Z" level=info msg="56ac2557b1ded11ccab7293dc47d1e88+44 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0]" time="2023-12-01T16:12:59.524039453Z" level=info msg="37b51d194a7513e45b56f6524f2d51f2+3 refs=32 needed=1 unneeded=0 pulling=2 map[archive:2 default:2] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=pull,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=pull,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=stay,12345678000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.524195933Z" level=info msg="5c77a43e329b9838cbec18ff42790e57+55605760 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.524206273Z" level=info msg="85877ca2d7e05498dd3d109baf2df106+95 refs=5 needed=0 unneeded=0 pulling=0 map[default:2] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.524204693Z" level=info msg="73feffa4b7f6bb68e44cf984c85f6e88+3 refs=220 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0]" time="2023-12-01T16:12:59.524215822Z" level=info msg="d21353cfe035e3e384563ee55eadbb2f+67108864 refs=2 needed=0 unneeded=0 pulling=0 map[default:2] [keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=none,0]" time="2023-12-01T16:12:59.524240253Z" level=info msg="changeset_compute: took 0.000531251s" time="2023-12-01T16:12:59.524244142Z" level=info msg="===" time="2023-12-01T16:12:59.524248653Z" level=info msg="17 replicas (17 blocks, 190080867 bytes) lost (0=have<want)" time="2023-12-01T16:12:59.524252933Z" level=info msg="2 replicas (1 blocks, 6 bytes) underreplicated (0<have<want)" time="2023-12-01T16:12:59.524256593Z" level=info msg="0 replicas (0 blocks, 0 bytes) just right (have=want)" time="2023-12-01T16:12:59.524260153Z" level=info msg="2 replicas (1 blocks, 6 bytes) overreplicated (have>want>0)" time="2023-12-01T16:12:59.524263473Z" level=info msg="0 replicas (0 blocks, 0 bytes) unreferenced (have>want=0, new)" time="2023-12-01T16:12:59.524266793Z" level=info msg="0 replicas (0 blocks, 0 bytes) garbage (have>want=0, old)" time="2023-12-01T16:12:59.524269622Z" level=info msg="===" time="2023-12-01T16:12:59.524272682Z" level=info msg="storage class \"default\": 3 replicas (2 blocks, 9 bytes) needed" time="2023-12-01T16:12:59.524276593Z" level=info msg="storage class \"default\": 2 replicas (1 blocks, 6 bytes) unneeded" time="2023-12-01T16:12:59.524280202Z" level=info msg="storage class \"default\": 2 replicas (1 blocks, 6 bytes) pulling" time="2023-12-01T16:12:59.524283893Z" level=info msg="storage class \"default\": 17 replicas (17 blocks, 190080867 bytes) unachievable" time="2023-12-01T16:12:59.524287762Z" level=info msg="===" time="2023-12-01T16:12:59.524290642Z" level=info msg="3 replicas (2 blocks, 9 bytes) total commitment (excluding unreferenced)" time="2023-12-01T16:12:59.524294182Z" level=info msg="5 replicas (2 blocks, 15 bytes) total usage" time="2023-12-01T16:12:59.524296893Z" level=info msg="===" time="2023-12-01T16:12:59.524301473Z" level=info msg="zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:1, Trashes:0} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.524307893Z" level=info msg="zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:0} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.524312682Z" level=info msg="zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:1, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.524317262Z" level=info msg="zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.524320853Z" level=info msg="===" time="2023-12-01T16:12:59.524323293Z" level=info msg="Replication level distribution:" time="2023-12-01T16:12:59.524327033Z" level=info msg=" 0: 17 #########################################################" time="2023-12-01T16:12:59.524330513Z" level=info msg=" 1: 1 #############" time="2023-12-01T16:12:59.524333173Z" level=info msg=" 2: 0 " time="2023-12-01T16:12:59.524335673Z" level=info msg=" 3: 0 " time="2023-12-01T16:12:59.524338413Z" level=info msg=" 4: 1 #############" time="2023-12-01T16:12:59.524340873Z" level=info msg="===" time="2023-12-01T16:12:59.524345462Z" level=info msg="send_pull_lists: start" time="2023-12-01T16:12:59.524461302Z" level=info msg="send_pull_lists: took 0.0001141s" time="2023-12-01T16:12:59.524467442Z" level=info msg="send_trash_lists: start" time="2023-12-01T16:12:59.524528722Z" level=info msg="send_trash_lists: took 6.046e-05s" time="2023-12-01T16:12:59.524534253Z" level=info msg="sweep: took 0.0026935s" time="2023-12-01T16:12:59.524719053Z" level=info msg="run succeeded" time="2023-12-01T16:12:59.524725393Z" level=info msg="timer went off" time="2023-12-01T16:12:59.524728422Z" level=info msg="starting next run" time="2023-12-01T16:12:59.524829733Z" level=info msg="acquiring active lock" time="2023-12-01T16:12:59.525009153Z" level=info msg="sweep: start" time="2023-12-01T16:12:59.525098873Z" level=info msg="skipping zzzzz-bi6l4-h0a0xwut9qa6g3a with service type \"proxy\"" time="2023-12-01T16:12:59.525320482Z" level=info msg="get_state: start" time="2023-12-01T16:12:59.525355213Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.525387462Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.525395702Z" level=info msg="zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.525400673Z" level=info msg="mount zzzzz-ivpuk-300000000000000 (keep3-vol0) on zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.525415002Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.525432922Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.525438253Z" level=info msg="zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.525442962Z" level=info msg="mount zzzzz-ivpuk-100000000000000 (keep1-vol0) on zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.525453602Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.525470402Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): add 2 entries to map" time="2023-12-01T16:12:59.525470022Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): retrieve index from zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk)" time="2023-12-01T16:12:59.525475713Z" level=info msg="zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): added 2 entries to map at 1x (2 replicas)" time="2023-12-01T16:12:59.525480433Z" level=info msg="mount zzzzz-ivpuk-000000000000000 (keep0-vol0) on zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.525500853Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): add 1 entries to map" time="2023-12-01T16:12:59.525508003Z" level=info msg="zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): added 1 entries to map at 1x (1 replicas)" time="2023-12-01T16:12:59.525513173Z" level=info msg="mount zzzzz-ivpuk-200000000000000 (keep2-vol0) on zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): index done" time="2023-12-01T16:12:59.525708013Z" level=info msg="collections: 0/3" time="2023-12-01T16:12:59.525782573Z" level=info msg="get_state: took 0.00046077s" time="2023-12-01T16:12:59.525790813Z" level=info msg="changeset_compute: start" time="2023-12-01T16:12:59.525816203Z" level=info msg="acbd18db4cc2f85cedef654fccc4a4d8+3 refs=0 needed=0 unneeded=4 pulling=0 map[] [keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=trash,12345695000000000 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=trash,12345697000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=trash,12345698000000000 keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=trash,12345696000000000]" time="2023-12-01T16:12:59.525833193Z" level=info msg="37b51d194a7513e45b56f6524f2d51f2+3 refs=0 needed=0 unneeded=1 pulling=0 map[] [keep1.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-100000000000000=none,0 keep3.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-300000000000000=none,0 keep0.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-000000000000000=trash,12345678000000000 keep2.zzzzz.arvadosapi.com:25107/zzzzz-ivpuk-200000000000000=none,0]" time="2023-12-01T16:12:59.525846693Z" level=info msg="changeset_compute: took 5.534e-05s" time="2023-12-01T16:12:59.525849713Z" level=info msg="===" time="2023-12-01T16:12:59.525853393Z" level=info msg="0 replicas (0 blocks, 0 bytes) lost (0=have<want)" time="2023-12-01T16:12:59.525856853Z" level=info msg="0 replicas (0 blocks, 0 bytes) underreplicated (0<have<want)" time="2023-12-01T16:12:59.525860763Z" level=info msg="0 replicas (0 blocks, 0 bytes) just right (have=want)" time="2023-12-01T16:12:59.525864373Z" level=info msg="0 replicas (0 blocks, 0 bytes) overreplicated (have>want>0)" time="2023-12-01T16:12:59.525868043Z" level=info msg="0 replicas (0 blocks, 0 bytes) unreferenced (have>want=0, new)" time="2023-12-01T16:12:59.525871493Z" level=info msg="5 replicas (2 blocks, 15 bytes) garbage (have>want=0, old)" time="2023-12-01T16:12:59.525874363Z" level=info msg="===" time="2023-12-01T16:12:59.525877313Z" level=info msg="storage class \"default\": 0 replicas (0 blocks, 0 bytes) needed" time="2023-12-01T16:12:59.525880963Z" level=info msg="storage class \"default\": 5 replicas (2 blocks, 15 bytes) unneeded" time="2023-12-01T16:12:59.525884543Z" level=info msg="storage class \"default\": 0 replicas (0 blocks, 0 bytes) pulling" time="2023-12-01T16:12:59.525888173Z" level=info msg="storage class \"default\": 0 replicas (0 blocks, 0 bytes) unachievable" time="2023-12-01T16:12:59.525891283Z" level=info msg="===" time="2023-12-01T16:12:59.525901563Z" level=info msg="0 replicas (0 blocks, 0 bytes) total commitment (excluding unreferenced)" time="2023-12-01T16:12:59.525905053Z" level=info msg="5 replicas (2 blocks, 15 bytes) total usage" time="2023-12-01T16:12:59.525907843Z" level=info msg="===" time="2023-12-01T16:12:59.525912093Z" level=info msg="zzzzz-bi6l4-000000000000002 (keep2.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.525918183Z" level=info msg="zzzzz-bi6l4-000000000000003 (keep3.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.525922843Z" level=info msg="zzzzz-bi6l4-000000000000000 (keep0.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:2} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.525927363Z" level=info msg="zzzzz-bi6l4-000000000000001 (keep1.zzzzz.arvadosapi.com:25107, disk): ChangeSet{Pulls:0, Trashes:1} Deferred{Pulls:0 Trashes:0}\n" time="2023-12-01T16:12:59.525930933Z" level=info msg="===" time="2023-12-01T16:12:59.525933173Z" level=info msg="Replication level distribution:" time="2023-12-01T16:12:59.525936823Z" level=info msg=" 0: 0 " time="2023-12-01T16:12:59.525939613Z" level=info msg=" 1: 1 #############################################" time="2023-12-01T16:12:59.525942543Z" level=info msg=" 2: 0 " time="2023-12-01T16:12:59.525945003Z" level=info msg=" 3: 0 " time="2023-12-01T16:12:59.525947413Z" level=info msg=" 4: 1 #############################################" time="2023-12-01T16:12:59.525950063Z" level=info msg="===" time="2023-12-01T16:12:59.525953763Z" level=info msg="sweep: took 0.000945301s" time="2023-12-01T16:12:59.526474783Z" level=info msg="run failed: received zero collections" time="2023-12-01T16:12:59.526481473Z" level=info msg="timer went off" time="2023-12-01T16:12:59.526484613Z" level=info msg="starting next run" time="2023-12-01T16:12:59.526645963Z" level=info msg="acquiring active lock" time="2023-12-01T16:12:59.526654103Z" level=info msg="run succeeded" time="2023-12-01T16:12:59.526657903Z" level=info msg="timer went off" time="2023-12-01T16:12:59.526660733Z" level=info msg="starting next run" balance_run_test.go:667: c.Check(metrics, check.Matches, `(?ms).*\narvados_keepbalance_changeset_compute_seconds_count `+fmt.Sprintf("%d", pullReqs.Count()/4)+`\n.*`) ... value string = "" + ... "# HELP arvados_keep_dedup_block_ratio deduplication ratio, blocks referenced / blocks stored\n" + ... "# TYPE arvados_keep_dedup_block_ratio gauge\n" + ... "arvados_keep_dedup_block_ratio 0\n" + ... "# HELP arvados_keep_dedup_byte_ratio deduplication ratio, bytes referenced / bytes stored\n" + ... "# TYPE arvados_keep_dedup_byte_ratio gauge\n" + ... "arvados_keep_dedup_byte_ratio 0\n" + ... "# HELP arvados_keep_garbage_blocks blocks of garbage (unreferenced, old)\n" + ... "# TYPE arvados_keep_garbage_blocks gauge\n" + ... "arvados_keep_garbage_blocks 2\n" + ... "# HELP arvados_keep_garbage_bytes bytes of garbage (unreferenced, old)\n" + ... "# TYPE arvados_keep_garbage_bytes gauge\n" + ... "arvados_keep_garbage_bytes 15\n" + ... "# HELP arvados_keep_garbage_replicas replicas of garbage (unreferenced, old)\n" + ... "# TYPE arvados_keep_garbage_replicas gauge\n" + ... "arvados_keep_garbage_replicas 5\n" + ... "# HELP arvados_keep_lost_blocks blocks of lost\n" + ... "# TYPE arvados_keep_lost_blocks gauge\n" + ... "arvados_keep_lost_blocks 0\n" + ... "# HELP arvados_keep_lost_bytes bytes of lost\n" + ... "# TYPE arvados_keep_lost_bytes gauge\n" + ... "arvados_keep_lost_bytes 0\n" + ... "# HELP arvados_keep_lost_replicas replicas of lost\n" + ... "# TYPE arvados_keep_lost_replicas gauge\n" + ... "arvados_keep_lost_replicas 0\n" + ... "# HELP arvados_keep_overreplicated_blocks blocks of overreplicated\n" + ... "# TYPE arvados_keep_overreplicated_blocks gauge\n" + ... "arvados_keep_overreplicated_blocks 0\n" + ... "# HELP arvados_keep_overreplicated_bytes bytes of overreplicated\n" + ... "# TYPE arvados_keep_overreplicated_bytes gauge\n" + ... "arvados_keep_overreplicated_bytes 0\n" + ... "# HELP arvados_keep_overreplicated_replicas replicas of overreplicated\n" + ... "# TYPE arvados_keep_overreplicated_replicas gauge\n" + ... "arvados_keep_overreplicated_replicas 0\n" + ... "# HELP arvados_keep_total_blocks blocks of current backend storage usage\n" + ... "# TYPE arvados_keep_total_blocks gauge\n" + ... "arvados_keep_total_blocks 2\n" + ... "# HELP arvados_keep_total_bytes bytes of current backend storage usage\n" + ... "# TYPE arvados_keep_total_bytes gauge\n" + ... "arvados_keep_total_bytes 15\n" + ... "# HELP arvados_keep_total_replicas replicas of current backend storage usage\n" + ... "# TYPE arvados_keep_total_replicas gauge\n" + ... "arvados_keep_total_replicas 5\n" + ... "# HELP arvados_keep_transient_blocks blocks of transient (unreferenced, new)\n" + ... "# TYPE arvados_keep_transient_blocks gauge\n" + ... "arvados_keep_transient_blocks 0\n" + ... "# HELP arvados_keep_transient_bytes bytes of transient (unreferenced, new)\n" + ... "# TYPE arvados_keep_transient_bytes gauge\n" + ... "arvados_keep_transient_bytes 0\n" + ... "# HELP arvados_keep_transient_replicas replicas of transient (unreferenced, new)\n" + ... "# TYPE arvados_keep_transient_replicas gauge\n" + ... "arvados_keep_transient_replicas 0\n" + ... "# HELP arvados_keep_underreplicated_blocks blocks of underreplicated\n" + ... "# TYPE arvados_keep_underreplicated_blocks gauge\n" + ... "arvados_keep_underreplicated_blocks 0\n" + ... "# HELP arvados_keep_underreplicated_bytes bytes of underreplicated\n" + ... "# TYPE arvados_keep_underreplicated_bytes gauge\n" + ... "arvados_keep_underreplicated_bytes 0\n" + ... "# HELP arvados_keep_underreplicated_replicas replicas of underreplicated\n" + ... "# TYPE arvados_keep_underreplicated_replicas gauge\n" + ... "arvados_keep_underreplicated_replicas 0\n" + ... "# HELP arvados_keepbalance_changeset_compute_seconds wall clock time to compute changesets\n" + ... "# TYPE arvados_keepbalance_changeset_compute_seconds summary\n" + ... "arvados_keepbalance_changeset_compute_seconds_sum 0.0015203100000000002\n" + ... "arvados_keepbalance_changeset_compute_seconds_count 5\n" + ... "# HELP arvados_keepbalance_get_state_seconds wall clock time to get current state\n" + ... "# TYPE arvados_keepbalance_get_state_seconds summary\n" + ... "arvados_keepbalance_get_state_seconds_sum 0.011799439\n" + ... "arvados_keepbalance_get_state_seconds_count 5\n" + ... "# HELP arvados_keepbalance_send_pull_lists_seconds wall clock time to send pull lists\n" + ... "# TYPE arvados_keepbalance_send_pull_lists_seconds summary\n" + ... "arvados_keepbalance_send_pull_lists_seconds_sum 0.00047651999999999997\n" + ... "arvados_keepbalance_send_pull_lists_seconds_count 4\n" + ... "# HELP arvados_keepbalance_send_trash_lists_seconds wall clock time to send trash lists\n" + ... "# TYPE arvados_keepbalance_send_trash_lists_seconds summary\n" + ... "arvados_keepbalance_send_trash_lists_seconds_sum 0.00036698000000000004\n" + ... "arvados_keepbalance_send_trash_lists_seconds_count 5\n" + ... "# HELP arvados_keepbalance_sweep_seconds wall clock time to run one full sweep\n" + ... "# TYPE arvados_keepbalance_sweep_seconds summary\n" + ... "arvados_keepbalance_sweep_seconds_sum 0.016458132\n" + ... "arvados_keepbalance_sweep_seconds_count 5\n" ... regex string = "(?ms).*\\narvados_keepbalance_changeset_compute_seconds_count 4\\n.*"
Files
Updated by 
Updated by 
Updated by
Actions