err.txt

pacer: assist ratio=+2.191528e+000 (scan 2 MB in 4->5 MB) workers=2+0
pacer: H_m_prev=2236962 h_t=+8.750000e-001 H_T=4194304 h_a=+1.611084e+000 H_a=5840896 h_g=+1.000000e+000 H_g=4473924 u_a=+3.007654e-001 u_g=+2.500000e-001 W_a=4463624 goalΔ=+1.250000e-001 actualΔ=+7.360841e-001 u_a/u_g=+1.203062e+000
pacer: sweep done at heap size 4MB; allocated 0MB of spans; swept 713 pages
gc 1 @0.837s 0%: 0.20+5.9+2.3 ms clock, 0.41+2.5/3.3/0+4.7 ms cpu, 4->5->4 MB, 5 MB goal, 8 P
pacer: assist ratio=+4.760623e+000 (scan 5 MB in 6->7 MB) workers=2+0
pacer: H_m_prev=4699992 h_t=+4.947227e-001 H_T=5748568 h_a=+5.412111e-001 H_a=7243680 h_g=+1.000000e+000 H_g=9399984 u_a=+2.640451e-001 u_g=+2.500000e-001 W_a=6868312 goalΔ=+5.052773e-001 actualΔ=+4.648840e-002 u_a/u_g=+1.056181e+000
gc 2 @0.851s 0%: 0.090+13+6.5 ms clock, 0.45+1.4/9.3/0.073+32 ms cpu, 6->6->6 MB, 7 MB goal, 8 P
pacer: sweep done at heap size 6MB; allocated 0MB of spans; swept 956 pages
2016/06/08 01:43:33 [I] Metric tank starting. Built from (none) - Go version go1.6
2016/06/08 01:43:33 INF    3 [metricpersist/tank] (nsqd:4150) connecting to nsqd
2016/06/08 01:43:33 [I] DefCache initialized in 3.850432ms. starting data consumption
2016/06/08 01:43:33 [I] persist consumer connected to nsqd
2016/06/08 01:43:33 [I] starting listener for metrics and http/debug on :6063
2016/06/08 01:43:33 INF    1 [metrics/tank] (nsqd:4150) connecting to nsqd
2016/06/08 01:43:33 [I] consumer connected to nsqd
2016/06/08 01:43:33 [I] consumer connected to nsqlookupd
pacer: assist ratio=+5.087428e+000 (scan 8 MB in 10->12 MB) workers=2+0
pacer: sweep done at heap size 11MB; allocated 5MB of spans; swept 956 pages
pacer: H_m_prev=7114248 h_t=+7.228113e-001 H_T=10958099 h_a=+9.997594e-001 H_a=14226784 h_g=+1.000000e+000 H_g=14228496 u_a=+2.562934e-001 u_g=+2.500000e-001 W_a=9275688 goalΔ=+2.771887e-001 actualΔ=+2.769481e-001 u_a/u_g=+1.025173e+000
gc 3 @1.023s 1%: 0.25+25+4.6 ms clock, 1.8+1.4/40/1.5+32 ms cpu, 10->13->12 MB, 12 MB goal, 8 P
pacer: sweep done at heap size 13MB; allocated 0MB of spans; swept 1771 pages
pacer: assist ratio=+3.531537e+000 (scan 10 MB in 17->20 MB) workers=2+0
pacer: sweep done at heap size 20MB; allocated 7MB of spans; swept 1771 pages
pacer: H_m_prev=13581832 h_t=+7.194457e-001 H_T=18666014 h_a=+7.225505e-001 H_a=23395392 h_g=+1.000000e+000 H_g=27163664 u_a=+3.100866e-001 u_g=+2.500000e-001 W_a=12218544 goalΔ=+2.805543e-001 actualΔ=+3.104788e-003 u_a/u_g=+1.240346e+000
gc 4 @1.081s 3%: 0.054+35+14 ms clock, 0.38+22/54/0.23+100 ms cpu, 17->22->19 MB, 20 MB goal, 8 P
pacer: sweep done at heap size 20MB; allocated 0MB of spans; swept 2878 pages
pacer: assist ratio=+6.617554e+000 (scan 15 MB in 31->33 MB) workers=2+0
pacer: H_m_prev=20904632 h_t=+8.577974e-001 H_T=32605874 h_a=+6.441126e-001 H_a=34369568 h_g=+1.000000e+000 H_g=41809264 u_a=+3.656764e-001 u_g=+2.500000e-001 W_a=15736504 goalΔ=+1.422026e-001 actualΔ=-2.136848e-001 u_a/u_g=+1.462706e+000
gc 5 @1.202s 4%: 9.2+29+1.0 ms clock, 36+35/35/0.024+4.2 ms cpu, 31->32->27 MB, 33 MB goal, 8 P
pacer: sweep done at heap size 27MB; allocated 0MB of spans; swept 4224 pages
pacer: assist ratio=+1.807902e+001 (scan 24 MB in 52->53 MB) workers=2+0
pacer: H_m_prev=28567888 h_t=+9.500000e-001 H_T=54935072 h_a=+9.300120e-001 H_a=55136368 h_g=+1.000000e+000 H_g=57135776 u_a=+4.186702e-001 u_g=+2.500000e-001 W_a=21096424 goalΔ=+5.000000e-002 actualΔ=-1.998795e-002 u_a/u_g=+1.674681e+000
gc 6 @1.547s 4%: 0.15+43+7.1 ms clock, 0.76+59/81/77+35 ms cpu, 52->52->37 MB, 53 MB goal, 8 P
pacer: sweep done at heap size 38MB; allocated 1MB of spans; swept 6762 pages
pacer: assist ratio=+1.759968e+001 (scan 32 MB in 72->74 MB) workers=2+0
pacer: H_m_prev=38936056 h_t=+9.500000e-001 H_T=75925309 h_a=+9.665404e-001 H_a=76569328 h_g=+1.000000e+000 H_g=77872112 u_a=+5.584084e-001 u_g=+2.500000e-001 W_a=27679912 goalΔ=+5.000000e-002 actualΔ=+1.654042e-002 u_a/u_g=+2.233634e+000
gc 7 @2.094s 4%: 2.0+38+3.3 ms clock, 16+105/67/35+26 ms cpu, 72->73->46 MB, 74 MB goal, 8 P
pacer: sweep done at heap size 48MB; allocated 1MB of spans; swept 9403 pages
pacer: assist ratio=+1.816188e+001 (scan 42 MB in 91->93 MB) workers=2+0
pacer: H_m_prev=49258952 h_t=+9.500000e-001 H_T=96054956 h_a=+9.743241e-001 H_a=97253136 h_g=+1.000000e+000 H_g=98517904 u_a=+5.977972e-001 u_g=+2.500000e-001 W_a=36113528 goalΔ=+5.000000e-002 actualΔ=+2.432410e-002 u_a/u_g=+2.391189e+000
gc 8 @3.584s 3%: 3.1+49+12 ms clock, 18+166/91/0.078+74 ms cpu, 91->92->60 MB, 93 MB goal, 8 P
pacer: sweep done at heap size 63MB; allocated 3MB of spans; swept 11918 pages
pacer: assist ratio=+1.376552e+001 (scan 44 MB in 117->120 MB) workers=2+0
pacer: H_m_prev=63220528 h_t=+9.459182e-001 H_T=123021978 h_a=+9.634107e-001 H_a=124127864 h_g=+1.000000e+000 H_g=126441056 u_a=+4.869996e-001 u_g=+2.500000e-001 W_a=40452160 goalΔ=+5.408175e-002 actualΔ=+1.749250e-002 u_a/u_g=+1.947998e+000
gc 9 @4.908s 3%: 1.6+82+5.2 ms clock, 13+160/126/11+41 ms cpu, 117->118->66 MB, 120 MB goal, 8 P
pacer: sweep done at heap size 71MB; allocated 5MB of spans; swept 15207 pages
pacer: assist ratio=+1.237172e+001 (scan 41 MB in 130->133 MB) workers=2+0
pacer: H_m_prev=70161520 h_t=+9.500000e-001 H_T=136814964 h_a=+9.688945e-001 H_a=138140632 h_g=+1.000000e+000 H_g=140323040 u_a=+5.152474e-001 u_g=+2.500000e-001 W_a=40702960 goalΔ=+5.000000e-002 actualΔ=+1.889452e-002 u_a/u_g=+2.060990e+000
gc 10 @5.661s 4%: 17+85+7.6 ms clock, 51+218/185/51+23 ms cpu, 130->131->69 MB, 133 MB goal, 8 P
pacer: sweep done at heap size 72MB; allocated 2MB of spans; swept 17245 pages
pacer: assist ratio=+1.213667e+001 (scan 41 MB in 134->138 MB) workers=2+0
pacer: H_m_prev=72571368 h_t=+9.500000e-001 H_T=141205365 h_a=+9.645311e-001 H_a=142568712 h_g=+1.000000e+000 H_g=145142736 u_a=+4.092757e-001 u_g=+2.500000e-001 W_a=40607976 goalΔ=+5.000000e-002 actualΔ=+1.453114e-002 u_a/u_g=+1.637103e+000
gc 11 @7.197s 4%: 1.3+100+22 ms clock, 9.5+129/147/156+155 ms cpu, 134->135->65 MB, 138 MB goal, 8 P
pacer: sweep done at heap size 68MB; allocated 3MB of spans; swept 17839 pages
pacer: assist ratio=+1.254133e+001 (scan 40 MB in 125->128 MB) workers=2+0
pacer: H_m_prev=68258712 h_t=+9.500000e-001 H_T=131412294 h_a=+9.532742e-001 H_a=133327984 h_g=+1.000000e+000 H_g=136517424 u_a=+3.508624e-001 u_g=+2.500000e-001 W_a=40502624 goalΔ=+5.000000e-002 actualΔ=+3.274243e-003 u_a/u_g=+1.403450e+000
gc 12 @8.983s 3%: 0.16+47+0.54 ms clock, 1.2+38/81/108+4.3 ms cpu, 125->127->66 MB, 128 MB goal, 8 P
pacer: sweep done at heap size 66MB; allocated 0MB of spans; swept 16878 pages
pacer: assist ratio=+1.238002e+001 (scan 40 MB in 126->129 MB) workers=2+0
pacer: H_m_prev=69454072 h_t=+9.500000e-001 H_T=132660730 h_a=+9.162559e-001 H_a=133091776 h_g=+1.000000e+000 H_g=138908144 u_a=+3.631725e-001 u_g=+2.500000e-001 W_a=40507376 goalΔ=+5.000000e-002 actualΔ=-3.374409e-002 u_a/u_g=+1.452690e+000
gc 13 @10.696s 3%: 0.061+54+0.60 ms clock, 0.48+49/78/98+4.8 ms cpu, 126->126->68 MB, 129 MB goal, 8 P
pacer: sweep done at heap size 68MB; allocated 0MB of spans; swept 16787 pages
pacer: assist ratio=+1.424298e+001 (scan 40 MB in 133->136 MB) workers=2+0
pacer: H_m_prev=71496968 h_t=+9.500000e-001 H_T=139377856 h_a=+9.866933e-001 H_a=142042544 h_g=+1.000000e+000 H_g=142993936 u_a=+3.951005e-001 u_g=+2.500000e-001 W_a=40491832 goalΔ=+5.000000e-002 actualΔ=+3.669325e-002 u_a/u_g=+1.580402e+000
gc 14 @12.581s 2%: 0.098+35+0.56 ms clock, 0.78+41/63/99+4.4 ms cpu, 133->135->71 MB, 136 MB goal, 8 P
pacer: sweep done at heap size 72MB; allocated 0MB of spans; swept 17928 pages
pacer: assist ratio=+1.067314e+001 (scan 40 MB in 136->139 MB) workers=2+0
pacer: H_m_prev=74993160 h_t=+9.460050e-001 H_T=142718306 h_a=+9.206803e-001 H_a=144037888 h_g=+1.000000e+000 H_g=149986320 u_a=+4.129576e-001 u_g=+2.500000e-001 W_a=40494608 goalΔ=+5.399505e-002 actualΔ=-2.532461e-002 u_a/u_g=+1.651831e+000
gc 15 @14.584s 2%: 0.067+45+0.42 ms clock, 0.54+59/85/44+3.4 ms cpu, 136->137->71 MB, 139 MB goal, 8 P
pacer: sweep done at heap size 71MB; allocated 0MB of spans; swept 18114 pages
pacer: assist ratio=+1.144086e+001 (scan 40 MB in 137->141 MB) workers=2+0
pacer: H_m_prev=74865032 h_t=+9.500000e-001 H_T=144189754 h_a=+9.294329e-001 H_a=144447056 h_g=+1.000000e+000 H_g=149730064 u_a=+2.798158e-001 u_g=+2.500000e-001 W_a=40579144 goalΔ=+5.000000e-002 actualΔ=-2.056710e-002 u_a/u_g=+1.119263e+000
gc 16 @16.588s 2%: 0.31+62+3.4 ms clock, 2.2+14/102/142+24 ms cpu, 137->137->70 MB, 141 MB goal, 8 P
pacer: sweep done at heap size 71MB; allocated 0MB of spans; swept 18170 pages
pacer: assist ratio=+1.237836e+001 (scan 40 MB in 138->141 MB) workers=2+0
pacer: H_m_prev=74367576 h_t=+9.500000e-001 H_T=145016773 h_a=+9.624518e-001 H_a=145942784 h_g=+1.000000e+000 H_g=148735152 u_a=+4.416857e-001 u_g=+2.500000e-001 W_a=40525864 goalΔ=+5.000000e-002 actualΔ=+1.245181e-002 u_a/u_g=+1.766743e+000
gc 17 @18.289s 2%: 3.6+55+15 ms clock, 25+93/109/76+109 ms cpu, 138->139->73 MB, 141 MB goal, 8 P
pacer: sweep done at heap size 75MB; allocated 1MB of spans; swept 18384 pages
pacer: assist ratio=+1.228916e+001 (scan 40 MB in 143->146 MB) workers=2+0
pacer: H_m_prev=77217640 h_t=+9.500000e-001 H_T=149977074 h_a=+9.548992e-001 H_a=150952704 h_g=+1.000000e+000 H_g=154435280 u_a=+4.205533e-001 u_g=+2.500000e-001 W_a=40580288 goalΔ=+5.000000e-002 actualΔ=+4.899217e-003 u_a/u_g=+1.682213e+000
gc 18 @20.388s 2%: 0.37+57+0.37 ms clock, 3.0+79/113/89+3.0 ms cpu, 143->143->73 MB, 146 MB goal, 8 P
pacer: sweep done at heap size 74MB; allocated 0MB of spans; swept 19086 pages
pacer: assist ratio=+1.167369e+001 (scan 40 MB in 143->147 MB) workers=2+0
pacer: H_m_prev=77438440 h_t=+9.500000e-001 H_T=150638373 h_a=+9.726916e-001 H_a=152762160 h_g=+1.000000e+000 H_g=154876880 u_a=+3.549741e-001 u_g=+2.500000e-001 W_a=40528112 goalΔ=+5.000000e-002 actualΔ=+2.269160e-002 u_a/u_g=+1.419896e+000
gc 19 @22.083s 2%: 0.16+61+0.77 ms clock, 1.2+52/88/85+6.2 ms cpu, 143->145->77 MB, 147 MB goal, 8 P
pacer: sweep done at heap size 78MB; allocated 0MB of spans; swept 19341 pages
pacer: assist ratio=+1.135084e+001 (scan 40 MB in 149->152 MB) workers=2+0
pacer: H_m_prev=81779208 h_t=+9.500000e-001 H_T=156227338 h_a=+9.326149e-001 H_a=158047712 h_g=+1.000000e+000 H_g=163558416 u_a=+4.090237e-001 u_g=+2.500000e-001 W_a=40536240 goalΔ=+5.000000e-002 actualΔ=-1.738515e-002 u_a/u_g=+1.636095e+000
gc 20 @24.288s 2%: 0.22+43+0.66 ms clock, 1.7+55/70/61+5.3 ms cpu, 149->150->77 MB, 152 MB goal, 8 P
pacer: sweep done at heap size 77MB; allocated 0MB of spans; swept 20036 pages
pacer: assist ratio=+1.088908e+001 (scan 40 MB in 149->153 MB) workers=2+0
pacer: H_m_prev=81673192 h_t=+9.500000e-001 H_T=156774368 h_a=+9.604609e-001 H_a=160117096 h_g=+1.000000e+000 H_g=163346384 u_a=+3.369205e-001 u_g=+2.500000e-001 W_a=40535360 goalΔ=+5.000000e-002 actualΔ=+1.046086e-002 u_a/u_g=+1.347682e+000
gc 21 @26.286s 1%: 0.091+57+0.69 ms clock, 0.73+40/88/61+5.5 ms cpu, 149->152->81 MB, 153 MB goal, 8 P
pacer: sweep done at heap size 83MB; allocated 1MB of spans; swept 20298 pages
pacer: assist ratio=+1.167457e+001 (scan 41 MB in 154->158 MB) workers=2+0
pacer: H_m_prev=85813080 h_t=+9.500000e-001 H_T=161685919 h_a=+9.259380e-001 H_a=165270672 h_g=+1.000000e+000 H_g=171626160 u_a=+3.986883e-001 u_g=+2.500000e-001 W_a=41283632 goalΔ=+5.000000e-002 actualΔ=-2.406200e-002 u_a/u_g=+1.594753e+000
gc 22 @28.106s 1%: 0.083+104+2.8 ms clock, 0.67+124/162/270+22 ms cpu, 154->157->86 MB, 158 MB goal, 8 P
pacer: sweep done at heap size 88MB; allocated 2MB of spans; swept 20931 pages
pacer: assist ratio=+9.862666e+000 (scan 41 MB in 163->168 MB) workers=2+0
pacer: H_m_prev=90866920 h_t=+9.500000e-001 H_T=171784860 h_a=+8.908979e-001 H_a=171820072 h_g=+1.000000e+000 H_g=181733840 u_a=+2.856216e-001 u_g=+2.500000e-001 W_a=41262568 goalΔ=+5.000000e-002 actualΔ=-5.910206e-002 u_a/u_g=+1.142486e+000
gc 23 @30.502s 1%: 0.054+35+0.31 ms clock, 0.43+10/68/120+2.5 ms cpu, 163->163->83 MB, 168 MB goal, 8 P
pacer: sweep done at heap size 83MB; allocated 0MB of spans; swept 21532 pages
pacer: assist ratio=+1.054042e+001 (scan 43 MB in 162->166 MB) workers=2+0
pacer: H_m_prev=87261672 h_t=+9.500000e-001 H_T=170160260 h_a=+9.842856e-001 H_a=173152080 h_g=+1.000000e+000 H_g=174523344 u_a=+4.998072e-001 u_g=+2.500000e-001 W_a=43534944 goalΔ=+5.000000e-002 actualΔ=+3.428561e-002 u_a/u_g=+1.999229e+000
gc 24 @32.592s 1%: 0.97+94+3.2 ms clock, 3.9+190/97/0.079+12 ms cpu, 162->165->95 MB, 166 MB goal, 8 P
pacer: sweep done at heap size 99MB; allocated 4MB of spans; swept 21582 pages
2016/06/08 01:44:05 INF    2 (nsqd:4150) connecting to nsqd
pacer: assist ratio=+9.087869e+000 (scan 47 MB in 180->186 MB) workers=2+0
pacer: H_m_prev=99822848 h_t=+9.407276e-001 H_T=189364183 h_a=+9.077736e-001 H_a=190439392 h_g=+1.000000e+000 H_g=199645696 u_a=+5.818532e-001 u_g=+2.500000e-001 W_a=44053320 goalΔ=+5.927239e-002 actualΔ=-3.295404e-002 u_a/u_g=+2.327413e+000
gc 25 @34.401s 1%: 2.4+62+3.7 ms clock, 14+176/99/0.72+22 ms cpu, 180->181->93 MB, 186 MB goal, 8 P
pacer: sweep done at heap size 97MB; allocated 3MB of spans; swept 23634 pages
pacer: assist ratio=+1.158341e+001 (scan 48 MB in 182->186 MB) workers=2+0
pacer: H_m_prev=98291752 h_t=+9.500000e-001 H_T=191105756 h_a=+9.731632e-001 H_a=193945664 h_g=+1.000000e+000 H_g=196583504 u_a=+3.606092e-001 u_g=+2.500000e-001 W_a=43715736 goalΔ=+5.000000e-002 actualΔ=+2.316316e-002 u_a/u_g=+1.442437e+000
gc 26 @36.382s 1%: 0.080+62+0.57 ms clock, 0.64+55/112/138+4.6 ms cpu, 182->184->96 MB, 186 MB goal, 8 P
pacer: sweep done at heap size 96MB; allocated 0MB of spans; swept 24151 pages
pacer: assist ratio=+9.339300e+000 (scan 43 MB in 183->188 MB) workers=2+0
pacer: H_m_prev=100787344 h_t=+9.500000e-001 H_T=192658861 h_a=+9.459745e-001 H_a=196129600 h_g=+1.000000e+000 H_g=201574688 u_a=+3.554714e-001 u_g=+2.500000e-001 W_a=43746280 goalΔ=+5.000000e-002 actualΔ=-4.025513e-003 u_a/u_g=+1.421885e+000
gc 27 @39.084s 1%: 0.059+44+0.44 ms clock, 0.47+37/76/136+3.5 ms cpu, 183->187->97 MB, 188 MB goal, 8 P
pacer: sweep done at heap size 98MB; allocated 0MB of spans; swept 24594 pages
pacer: assist ratio=+9.246410e+000 (scan 43 MB in 184->189 MB) workers=2+0
pacer: H_m_prev=102661504 h_t=+9.500000e-001 H_T=193809673 h_a=+9.077419e-001 H_a=195851656 h_g=+1.000000e+000 H_g=205323008 u_a=+3.575339e-001 u_g=+2.500000e-001 W_a=43750624 goalΔ=+5.000000e-002 actualΔ=-4.225807e-002 u_a/u_g=+1.430136e+000
gc 28 @41.583s 1%: 0.37+41+0.51 ms clock, 2.9+36/79/146+4.1 ms cpu, 184->186->100 MB, 189 MB goal, 8 P
pacer: sweep done at heap size 101MB; allocated 0MB of spans; swept 24588 pages
pacer: assist ratio=+9.575112e+000 (scan 44 MB in 193->197 MB) workers=2+0
pacer: H_m_prev=105456528 h_t=+9.500000e-001 H_T=202292641 h_a=+9.393899e-001 H_a=204521328 h_g=+1.000000e+000 H_g=210913056 u_a=+4.265095e-001 u_g=+2.500000e-001 W_a=43716600 goalΔ=+5.000000e-002 actualΔ=-1.061007e-002 u_a/u_g=+1.706038e+000
gc 29 @44.482s 1%: 8.0+37+0.61 ms clock, 64+64/84/108+4.9 ms cpu, 193->195->100 MB, 197 MB goal, 8 P
pacer: sweep done at heap size 101MB; allocated 0MB of spans; swept 25603 pages
pacer: assist ratio=+8.873892e+000 (scan 43 MB in 192->197 MB) workers=2+0
pacer: H_m_prev=105109216 h_t=+9.500000e-001 H_T=201854296 h_a=+9.247842e-001 H_a=202312560 h_g=+1.000000e+000 H_g=210218432 u_a=+4.318453e-001 u_g=+2.500000e-001 W_a=43778688 goalΔ=+5.000000e-002 actualΔ=-2.521578e-002 u_a/u_g=+1.727381e+000
gc 30 @46.904s 1%: 0.11+66+4.1 ms clock, 0.77+97/118/91+28 ms cpu, 192->192->102 MB, 197 MB goal, 8 P
pacer: sweep done at heap size 105MB; allocated 3MB of spans; swept 25312 pages
pacer: assist ratio=+8.600566e+000 (scan 44 MB in 200->205 MB) workers=2+0
pacer: H_m_prev=107584152 h_t=+9.500000e-001 H_T=209789096 h_a=+9.739620e-001 H_a=212367032 h_g=+1.000000e+000 H_g=215168304 u_a=+3.815081e-001 u_g=+2.500000e-001 W_a=43767816 goalΔ=+5.000000e-002 actualΔ=+2.396204e-002 u_a/u_g=+1.526032e+000
gc 31 @49.601s 1%: 0.10+38+0.48 ms clock, 0.75+40/75/101+3.3 ms cpu, 200->202->106 MB, 205 MB goal, 8 P
pacer: sweep done at heap size 106MB; allocated 0MB of spans; swept 26666 pages
pacer: assist ratio=+8.666153e+000 (scan 44 MB in 203->208 MB) workers=2+0
pacer: H_m_prev=111481088 h_t=+9.500000e-001 H_T=213067561 h_a=+9.177586e-001 H_a=213793816 h_g=+1.000000e+000 H_g=222962176 u_a=+2.896653e-001 u_g=+2.500000e-001 W_a=43848752 goalΔ=+5.000000e-002 actualΔ=-3.224139e-002 u_a/u_g=+1.158661e+000
gc 32 @52.391s 1%: 0.23+60+0.75 ms clock, 1.9+19/110/158+6.0 ms cpu, 203->203->106 MB, 208 MB goal, 8 P
pacer: sweep done at heap size 106MB; allocated 0MB of spans; swept 27029 pages
pacer: assist ratio=+8.319605e+000 (scan 43 MB in 206->211 MB) workers=2+0
pacer: H_m_prev=111207488 h_t=+9.500000e-001 H_T=216271005 h_a=+9.640679e-001 H_a=218419056 h_g=+1.000000e+000 H_g=222414976 u_a=+4.527461e-001 u_g=+2.500000e-001 W_a=43760608 goalΔ=+5.000000e-002 actualΔ=+1.406789e-002 u_a/u_g=+1.810984e+000
gc 33 @54.896s 1%: 0.31+41+0.39 ms clock, 2.2+68/80/94+2.7 ms cpu, 206->208->112 MB, 211 MB goal, 8 P
pacer: sweep done at heap size 113MB; allocated 0MB of spans; swept 27490 pages
pacer: assist ratio=+7.993904e+000 (scan 44 MB in 216->222 MB) workers=2+0
pacer: H_m_prev=118244688 h_t=+9.500000e-001 H_T=227134050 h_a=+9.422975e-001 H_a=229666360 h_g=+1.000000e+000 H_g=236489376 u_a=+3.646868e-001 u_g=+2.500000e-001 W_a=43771352 goalΔ=+5.000000e-002 actualΔ=-7.702516e-003 u_a/u_g=+1.458747e+000
gc 34 @58.082s 1%: 0.050+38+0.55 ms clock, 0.40+35/74/109+4.4 ms cpu, 216->219->112 MB, 222 MB goal, 8 P
pacer: sweep done at heap size 112MB; allocated 0MB of spans; swept 28849 pages
pacer: assist ratio=+8.047921e+000 (scan 44 MB in 215->220 MB) workers=2+0
pacer: H_m_prev=118155696 h_t=+9.500000e-001 H_T=225836379 h_a=+9.198524e-001 H_a=226841496 h_g=+1.000000e+000 H_g=236311392 u_a=+3.780873e-001 u_g=+2.500000e-001 W_a=43835608 goalΔ=+5.000000e-002 actualΔ=-3.014760e-002 u_a/u_g=+1.512349e+000
gc 35 @61.186s 1%: 0.067+80+7.9 ms clock, 0.54+83/143/162+63 ms cpu, 215->216->112 MB, 220 MB goal, 8 P
pacer: sweep done at heap size 116MB; allocated 3MB of spans; swept 28338 pages
pacer: assist ratio=+7.828632e+000 (scan 43 MB in 218->224 MB) workers=2+0
pacer: H_m_prev=118372360 h_t=+9.500000e-001 H_T=229486296 h_a=+9.419538e-001 H_a=229873656 h_g=+1.000000e+000 H_g=236744720 u_a=+2.679471e-001 u_g=+2.500000e-001 W_a=43720736 goalΔ=+5.000000e-002 actualΔ=-8.046186e-003 u_a/u_g=+1.071789e+000
gc 36 @63.603s 1%: 0.19+36+0.37 ms clock, 1.5+5.2/69/165+3.0 ms cpu, 218->219->118 MB, 224 MB goal, 8 P
pacer: sweep done at heap size 118MB; allocated 0MB of spans; swept 28794 pages
pacer: assist ratio=+7.551592e+000 (scan 44 MB in 230->236 MB) workers=2+0
pacer: H_m_prev=124114120 h_t=+9.500000e-001 H_T=242022534 h_a=+9.777811e-001 H_a=245470560 h_g=+1.000000e+000 H_g=248228240 u_a=+3.855204e-001 u_g=+2.500000e-001 W_a=43793208 goalΔ=+5.000000e-002 actualΔ=+2.778109e-002 u_a/u_g=+1.542082e+000
gc 37 @67.078s 1%: 0.082+74+2.5 ms clock, 0.65+82/128/131+20 ms cpu, 230->234->120 MB, 236 MB goal, 8 P
pacer: sweep done at heap size 124MB; allocated 3MB of spans; swept 30971 pages
pacer: assist ratio=+8.188779e+000 (scan 44 MB in 229->235 MB) workers=2+0
pacer: H_m_prev=126593560 h_t=+9.500000e-001 H_T=240656629 h_a=+9.128341e-001 H_a=242152480 h_g=+1.000000e+000 H_g=253187120 u_a=+3.482057e-001 u_g=+2.500000e-001 W_a=43811656 goalΔ=+5.000000e-002 actualΔ=-3.716589e-002 u_a/u_g=+1.392823e+000
gc 38 @70.388s 1%: 0.13+83+0.60 ms clock, 1.0+65/127/95+4.8 ms cpu, 229->230->120 MB, 235 MB goal, 8 P
pacer: sweep done at heap size 124MB; allocated 3MB of spans; swept 30437 pages
pacer: assist ratio=+7.450924e+000 (scan 44 MB in 233->239 MB) workers=2+0
pacer: H_m_prev=126280152 h_t=+9.500000e-001 H_T=244808756 h_a=+9.418718e-001 H_a=245219864 h_g=+1.000000e+000 H_g=252560304 u_a=+3.124878e-001 u_g=+2.500000e-001 W_a=43840544 goalΔ=+5.000000e-002 actualΔ=-8.128216e-003 u_a/u_g=+1.249951e+000
gc 39 @73.691s 1%: 0.20+57+0.50 ms clock, 1.6+29/107/109+4.0 ms cpu, 233->233->121 MB, 239 MB goal, 8 P
pacer: sweep done at heap size 123MB; allocated 2MB of spans; swept 30807 pages
pacer: assist ratio=+7.629520e+000 (scan 43 MB in 237->242 MB) workers=2+0
pacer: H_m_prev=127391480 h_t=+9.500000e-001 H_T=248298304 h_a=+9.559218e-001 H_a=249167768 h_g=+1.000000e+000 H_g=254782960 u_a=+3.075334e-001 u_g=+2.500000e-001 W_a=43788112 goalΔ=+5.000000e-002 actualΔ=+5.921762e-003 u_a/u_g=+1.230134e+000
gc 40 @76.288s 1%: 0.17+59+0.53 ms clock, 1.3+27/96/139+4.2 ms cpu, 237->237->129 MB, 242 MB goal, 8 P
pacer: sweep done at heap size 129MB; allocated 0MB of spans; swept 31437 pages
pacer: assist ratio=+7.162844e+000 (scan 44 MB in 251->257 MB) workers=2+0
pacer: H_m_prev=135437320 h_t=+9.500000e-001 H_T=263633058 h_a=+9.601068e-001 H_a=265471608 h_g=+1.000000e+000 H_g=270874640 u_a=+3.489352e-001 u_g=+2.500000e-001 W_a=43818944 goalΔ=+5.000000e-002 actualΔ=+1.010677e-002 u_a/u_g=+1.395741e+000
gc 41 @80.085s 1%: 0.083+48+0.54 ms clock, 0.67+38/87/87+4.3 ms cpu, 251->253->130 MB, 257 MB goal, 8 P
pacer: sweep done at heap size 130MB; allocated 0MB of spans; swept 33047 pages
pacer: assist ratio=+7.072873e+000 (scan 44 MB in 250->257 MB) workers=2+0
pacer: H_m_prev=136360440 h_t=+9.500000e-001 H_T=263016702 h_a=+9.450050e-001 H_a=265221744 h_g=+1.000000e+000 H_g=272720880 u_a=+3.379747e-001 u_g=+2.500000e-001 W_a=43771032 goalΔ=+5.000000e-002 actualΔ=-4.994953e-003 u_a/u_g=+1.351899e+000
gc 42 @83.683s 1%: 0.23+48+0.63 ms clock, 1.8+34/79/103+5.0 ms cpu, 250->252->131 MB, 257 MB goal, 8 P
pacer: sweep done at heap size 131MB; allocated 0MB of spans; swept 32999 pages
pacer: assist ratio=+7.463784e+000 (scan 44 MB in 254->259 MB) workers=2+0
pacer: H_m_prev=138105384 h_t=+9.500000e-001 H_T=265813189 h_a=+9.430408e-001 H_a=268344400 h_g=+1.000000e+000 H_g=276210768 u_a=+3.457425e-001 u_g=+2.500000e-001 W_a=43797496 goalΔ=+5.000000e-002 actualΔ=-6.959170e-003 u_a/u_g=+1.382970e+000
gc 43 @87.283s 1%: 0.12+58+0.43 ms clock, 0.96+45/115/154+3.4 ms cpu, 254->255->132 MB, 259 MB goal, 8 P
pacer: sweep done at heap size 133MB; allocated 0MB of spans; swept 33390 pages
pacer: assist ratio=+6.780815e+000 (scan 44 MB in 256->262 MB) workers=2+0
pacer: H_m_prev=139345832 h_t=+9.500000e-001 H_T=268446250 h_a=+9.277057e-001 H_a=268617752 h_g=+1.000000e+000 H_g=278691664 u_a=+2.779989e-001 u_g=+2.500000e-001 W_a=43936280 goalΔ=+5.000000e-002 actualΔ=-2.229432e-002 u_a/u_g=+1.111996e+000
gc 44 @89.787s 1%: 1.0+62+1.1 ms clock, 7.3+14/120/190+7.8 ms cpu, 256->256->141 MB, 262 MB goal, 8 P
pacer: sweep done at heap size 142MB; allocated 0MB of spans; swept 33512 pages
pacer: assist ratio=+6.965120e+000 (scan 49 MB in 276->283 MB) workers=2+0
pacer: H_m_prev=148441160 h_t=+9.500000e-001 H_T=289460262 h_a=+9.705252e-001 H_a=292507040 h_g=+1.000000e+000 H_g=296882320 u_a=+6.998644e-001 u_g=+2.500000e-001 W_a=44682312 goalΔ=+5.000000e-002 actualΔ=+2.052516e-002 u_a/u_g=+2.799458e+000
gc 45 @92.978s 1%: 0.097+54+0.58 ms clock, 0.38+197/97/5.3+2.3 ms cpu, 276->278->145 MB, 283 MB goal, 8 P
pacer: sweep done at heap size 150MB; allocated 5MB of spans; swept 36153 pages
pacer: assist ratio=+6.545719e+000 (scan 50 MB in 279->286 MB) workers=2+0
pacer: H_m_prev=152321296 h_t=+9.462703e-001 H_T=292723264 h_a=+9.384077e-001 H_a=295260776 h_g=+1.000000e+000 H_g=304642592 u_a=+3.803418e-001 u_g=+2.500000e-001 W_a=44368032 goalΔ=+5.372965e-002 actualΔ=-7.862627e-003 u_a/u_g=+1.521367e+000
gc 46 @95.686s 1%: 0.23+57+0.65 ms clock, 1.6+60/111/108+4.5 ms cpu, 279->281->147 MB, 286 MB goal, 8 P
pacer: sweep done at heap size 148MB; allocated 1MB of spans; swept 36602 pages
pacer: assist ratio=+6.484794e+000 (scan 45 MB in 284->291 MB) workers=2+0
pacer: H_m_prev=154720696 h_t=+9.500000e-001 H_T=297629841 h_a=+9.427214e-001 H_a=300579208 h_g=+1.000000e+000 H_g=309441392 u_a=+3.758798e-001 u_g=+2.500000e-001 W_a=44369712 goalΔ=+5.000000e-002 actualΔ=-7.278594e-003 u_a/u_g=+1.503519e+000
gc 47 @99.580s 1%: 0.074+57+0.88 ms clock, 0.59+58/105/108+7.0 ms cpu, 284->286->153 MB, 291 MB goal, 8 P
pacer: sweep done at heap size 153MB; allocated 0MB of spans; swept 37426 pages
pacer: assist ratio=+6.084442e+000 (scan 45 MB in 294->302 MB) workers=2+0
pacer: H_m_prev=160865432 h_t=+9.500000e-001 H_T=309058230 h_a=+9.368846e-001 H_a=311577776 h_g=+1.000000e+000 H_g=321730864 u_a=+3.069095e-001 u_g=+2.500000e-001 W_a=44319328 goalΔ=+5.000000e-002 actualΔ=-1.311541e-002 u_a/u_g=+1.227638e+000
gc 48 @103.982s 1%: 0.043+43+0.43 ms clock, 0.34+19/86/101+3.5 ms cpu, 294->297->153 MB, 302 MB goal, 8 P
pacer: sweep done at heap size 154MB; allocated 0MB of spans; swept 38659 pages
pacer: assist ratio=+6.361506e+000 (scan 45 MB in 295->303 MB) workers=2+0
pacer: H_m_prev=161022520 h_t=+9.500000e-001 H_T=309831818 h_a=+9.385681e-001 H_a=312153128 h_g=+1.000000e+000 H_g=322045040 u_a=+3.428064e-001 u_g=+2.500000e-001 W_a=44341688 goalΔ=+5.000000e-002 actualΔ=-1.143185e-002 u_a/u_g=+1.371226e+000
gc 49 @107.982s 1%: 0.069+45+0.70 ms clock, 0.55+34/87/100+5.6 ms cpu, 295->297->155 MB, 303 MB goal, 8 P
pacer: sweep done at heap size 156MB; allocated 0MB of spans; swept 38744 pages
pacer: assist ratio=+5.904779e+000 (scan 45 MB in 301->309 MB) workers=2+0
pacer: H_m_prev=163569016 h_t=+9.500000e-001 H_T=316031055 h_a=+9.478002e-001 H_a=318599768 h_g=+1.000000e+000 H_g=327138032 u_a=+2.863424e-001 u_g=+2.500000e-001 W_a=44341816 goalΔ=+5.000000e-002 actualΔ=-2.199764e-003 u_a/u_g=+1.145370e+000
gc 50 @111.982s 1%: 0.050+42+0.39 ms clock, 0.40+12/72/132+3.1 ms cpu, 301->303->159 MB, 309 MB goal, 8 P
pacer: sweep done at heap size 159MB; allocated 0MB of spans; swept 39649 pages
pacer: assist ratio=+5.785411e+000 (scan 45 MB in 306->314 MB) workers=2+0
pacer: H_m_prev=167148472 h_t=+9.500000e-001 H_T=321680954 h_a=+9.398800e-001 H_a=324247976 h_g=+1.000000e+000 H_g=334296944 u_a=+2.968783e-001 u_g=+2.500000e-001 W_a=44344688 goalΔ=+5.000000e-002 actualΔ=-1.012001e-002 u_a/u_g=+1.187513e+000
gc 51 @115.882s 0%: 0.043+46+0.34 ms clock, 0.35+17/91/134+2.7 ms cpu, 306->309->165 MB, 314 MB goal, 8 P
pacer: sweep done at heap size 165MB; allocated 0MB of spans; swept 40400 pages
pacer: assist ratio=+5.696596e+000 (scan 46 MB in 319->327 MB) workers=2+0
pacer: H_m_prev=173883592 h_t=+9.500000e-001 H_T=334915744 h_a=+9.330358e-001 H_a=336123208 h_g=+1.000000e+000 H_g=347767184 u_a=+3.286288e-001 u_g=+2.500000e-001 W_a=44383944 goalΔ=+5.000000e-002 actualΔ=-1.696420e-002 u_a/u_g=+1.314515e+000
gc 52 @120.585s 0%: 0.064+55+0.61 ms clock, 0.45+35/110/120+4.2 ms cpu, 319->320->166 MB, 327 MB goal, 8 P
pacer: sweep done at heap size 166MB; allocated 0MB of spans; swept 41688 pages
pacer: assist ratio=+5.554460e+000 (scan 45 MB in 322->330 MB) workers=2+0
pacer: H_m_prev=174115496 h_t=+9.500000e-001 H_T=338201713 h_a=+9.484180e-001 H_a=339249760 h_g=+1.000000e+000 H_g=348230992 u_a=+3.792593e-001 u_g=+2.500000e-001 W_a=44324856 goalΔ=+5.000000e-002 actualΔ=-1.582037e-003 u_a/u_g=+1.517037e+000
gc 53 @124.488s 0%: 0.066+37+1.2 ms clock, 0.53+39/72/105+9.8 ms cpu, 322->323->173 MB, 330 MB goal, 8 P
pacer: sweep done at heap size 173MB; allocated 0MB of spans; swept 42114 pages
pacer: assist ratio=+5.390534e+000 (scan 46 MB in 336->344 MB) workers=2+0
pacer: H_m_prev=181523960 h_t=+9.500000e-001 H_T=352649606 h_a=+9.453613e-001 H_a=353129680 h_g=+1.000000e+000 H_g=363047920 u_a=+2.964098e-001 u_g=+2.500000e-001 W_a=44400592 goalΔ=+5.000000e-002 actualΔ=-4.638737e-003 u_a/u_g=+1.185639e+000
gc 54 @129.488s 0%: 0.14+52+3.3 ms clock, 1.0+19/86/98+23 ms cpu, 336->336->172 MB, 344 MB goal, 8 P
pacer: sweep done at heap size 173MB; allocated 0MB of spans; swept 43975 pages
pacer: assist ratio=+5.335082e+000 (scan 45 MB in 336->345 MB) workers=2+0
pacer: H_m_prev=181099912 h_t=+9.500000e-001 H_T=352920282 h_a=+9.795993e-001 H_a=358505264 h_g=+1.000000e+000 H_g=362199824 u_a=+2.784400e-001 u_g=+2.500000e-001 W_a=44310552 goalΔ=+5.000000e-002 actualΔ=+2.959933e-002 u_a/u_g=+1.113760e+000
gc 55 @133.896s 0%: 0.43+45+0.43 ms clock, 3.0+10/74/150+3.0 ms cpu, 336->341->180 MB, 345 MB goal, 8 P
pacer: sweep done at heap size 186MB; allocated 5MB of spans; swept 44654 pages
pacer: assist ratio=+5.348173e+000 (scan 46 MB in 343->351 MB) workers=2+0
pacer: H_m_prev=189644296 h_t=+9.500000e-001 H_T=359616987 h_a=+9.028934e-001 H_a=360872872 h_g=+1.000000e+000 H_g=379288592 u_a=+2.827508e-001 u_g=+2.500000e-001 W_a=44402024 goalΔ=+5.000000e-002 actualΔ=-4.710664e-002 u_a/u_g=+1.131003e+000
gc 56 @138.489s 0%: 1.8+41+0.36 ms clock, 12+11/77/134+2.5 ms cpu, 343->344->182 MB, 351 MB goal, 8 P
pacer: sweep done at heap size 183MB; allocated 0MB of spans; swept 45345 pages
pacer: assist ratio=+5.165280e+000 (scan 46 MB in 355->364 MB) workers=2+0
pacer: H_m_prev=191816264 h_t=+9.500000e-001 H_T=372500809 h_a=+9.573564e-001 H_a=375452784 h_g=+1.000000e+000 H_g=383632528 u_a=+3.739794e-001 u_g=+2.500000e-001 W_a=44314544 goalΔ=+5.000000e-002 actualΔ=+7.356358e-003 u_a/u_g=+1.495918e+000
gc 57 @143.680s 0%: 0.086+43+4.0 ms clock, 0.68+43/68/74+32 ms cpu, 355->358->183 MB, 364 MB goal, 8 P
pacer: sweep done at heap size 184MB; allocated 0MB of spans; swept 46469 pages
pacer: assist ratio=+5.112750e+000 (scan 46 MB in 353->362 MB) workers=2+0
pacer: H_m_prev=192452936 h_t=+9.500000e-001 H_T=370317994 h_a=+9.433621e-001 H_a=374005736 h_g=+1.000000e+000 H_g=384905872 u_a=+3.457406e-001 u_g=+2.500000e-001 W_a=44305736 goalΔ=+5.000000e-002 actualΔ=-6.637930e-003 u_a/u_g=+1.382963e+000
gc 58 @147.804s 0%: 0.075+48+0.34 ms clock, 0.52+37/90/151+2.4 ms cpu, 353->356->193 MB, 362 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 2MB of spans; swept 46264 pages
scvg0: inuse: 282, idle: 81, sys: 364, released: 0, consumed: 364 (MB)
pacer: assist ratio=+5.093688e+000 (scan 48 MB in 371->381 MB) workers=2+0
pacer: H_m_prev=203045560 h_t=+9.500000e-001 H_T=389718716 h_a=+9.234391e-001 H_a=390545760 h_g=+1.000000e+000 H_g=406091120 u_a=+7.589815e-001 u_g=+2.500000e-001 W_a=44875392 goalΔ=+5.000000e-002 actualΔ=-2.656095e-002 u_a/u_g=+3.035926e+000
gc 59 @152.597s 0%: 1.0+39+0.90 ms clock, 4.1+166/76/0.55+3.6 ms cpu, 371->372->174 MB, 381 MB goal, 8 P
pacer: sweep done at heap size 184MB; allocated 9MB of spans; swept 48434 pages
pacer: assist ratio=+6.137758e+000 (scan 53 MB in 339->348 MB) workers=2+0
pacer: H_m_prev=182634432 h_t=+9.500000e-001 H_T=356122260 h_a=+9.686865e-001 H_a=359549944 h_g=+1.000000e+000 H_g=365268864 u_a=+3.440963e-001 u_g=+2.500000e-001 W_a=44410360 goalΔ=+5.000000e-002 actualΔ=+1.868652e-002 u_a/u_g=+1.376385e+000
gc 60 @155.691s 0%: 0.055+67+5.4 ms clock, 0.44+50/132/201+43 ms cpu, 339->342->178 MB, 348 MB goal, 8 P
pacer: sweep done at heap size 182MB; allocated 3MB of spans; swept 44483 pages
pacer: assist ratio=+5.655095e+000 (scan 46 MB in 342->350 MB) workers=2+0
pacer: H_m_prev=187041672 h_t=+9.500000e-001 H_T=358763277 h_a=+9.349117e-001 H_a=361909128 h_g=+1.000000e+000 H_g=374083344 u_a=+3.400229e-001 u_g=+2.500000e-001 W_a=44302792 goalΔ=+5.000000e-002 actualΔ=-1.508825e-002 u_a/u_g=+1.360092e+000
gc 61 @160.482s 0%: 0.054+37+1.6 ms clock, 0.43+27/73/138+13 ms cpu, 342->345->184 MB, 350 MB goal, 8 P
pacer: sweep done at heap size 184MB; allocated 0MB of spans; swept 45100 pages
pacer: assist ratio=+5.130896e+000 (scan 46 MB in 354->363 MB) workers=2+0
pacer: H_m_prev=193000792 h_t=+9.500000e-001 H_T=371917790 h_a=+9.276524e-001 H_a=372038440 h_g=+1.000000e+000 H_g=386001584 u_a=+4.192311e-001 u_g=+2.500000e-001 W_a=44354808 goalΔ=+5.000000e-002 actualΔ=-2.234760e-002 u_a/u_g=+1.676925e+000
gc 62 @165.694s 0%: 0.21+44+0.48 ms clock, 1.7+60/87/93+3.8 ms cpu, 354->354->183 MB, 363 MB goal, 8 P
pacer: sweep done at heap size 184MB; allocated 1MB of spans; swept 46161 pages
pacer: assist ratio=+5.028642e+000 (scan 46 MB in 356->366 MB) workers=2+0
pacer: H_m_prev=191938392 h_t=+9.500000e-001 H_T=374279864 h_a=+9.636570e-001 H_a=376901160 h_g=+1.000000e+000 H_g=383876784 u_a=+2.991727e-001 u_g=+2.500000e-001 W_a=44371152 goalΔ=+5.000000e-002 actualΔ=+1.365696e-002 u_a/u_g=+1.196691e+000
gc 63 @170.182s 0%: 0.051+41+0.58 ms clock, 0.41+16/78/118+4.6 ms cpu, 356->359->190 MB, 366 MB goal, 8 P
pacer: sweep done at heap size 190MB; allocated 0MB of spans; swept 46822 pages
pacer: assist ratio=+4.929660e+000 (scan 46 MB in 366->375 MB) workers=2+0
pacer: H_m_prev=199450824 h_t=+9.500000e-001 H_T=384324080 h_a=+9.395955e-001 H_a=386853912 h_g=+1.000000e+000 H_g=398901648 u_a=+2.955675e-001 u_g=+2.500000e-001 W_a=44363136 goalΔ=+5.000000e-002 actualΔ=-1.040454e-002 u_a/u_g=+1.182270e+000
gc 64 @174.984s 0%: 0.052+54+0.57 ms clock, 0.41+19/96/105+4.6 ms cpu, 366->368->195 MB, 375 MB goal, 8 P
pacer: sweep done at heap size 199MB; allocated 3MB of spans; swept 48152 pages
pacer: assist ratio=+4.897561e+000 (scan 46 MB in 378->387 MB) workers=2+0
pacer: H_m_prev=205351704 h_t=+9.500000e-001 H_T=396413784 h_a=+9.404793e-001 H_a=398480728 h_g=+1.000000e+000 H_g=410703408 u_a=+3.469987e-001 u_g=+2.500000e-001 W_a=44376536 goalΔ=+5.000000e-002 actualΔ=-9.520714e-003 u_a/u_g=+1.387995e+000
gc 65 @180.583s 0%: 0.076+51+2.4 ms clock, 0.61+40/90/97+19 ms cpu, 378->380->196 MB, 387 MB goal, 8 P
pacer: sweep done at heap size 197MB; allocated 1MB of spans; swept 49470 pages
pacer: assist ratio=+4.755424e+000 (scan 46 MB in 379->389 MB) workers=2+0
pacer: H_m_prev=205615560 h_t=+9.500000e-001 H_T=397855255 h_a=+9.357663e-001 H_a=398023664 h_g=+1.000000e+000 H_g=411231120 u_a=+3.708185e-001 u_g=+2.500000e-001 W_a=44319296 goalΔ=+5.000000e-002 actualΔ=-1.423374e-002 u_a/u_g=+1.483274e+000
gc 66 @185.295s 0%: 0.068+35+0.86 ms clock, 0.54+34/68/126+6.9 ms cpu, 379->379->200 MB, 389 MB goal, 8 P
pacer: sweep done at heap size 201MB; allocated 0MB of spans; swept 49419 pages
pacer: assist ratio=+4.731757e+000 (scan 47 MB in 392->401 MB) workers=2+0
pacer: H_m_prev=210748152 h_t=+9.500000e-001 H_T=410958896 h_a=+9.597285e-001 H_a=413009152 h_g=+1.000000e+000 H_g=421496304 u_a=+3.160396e-001 u_g=+2.500000e-001 W_a=44353472 goalΔ=+5.000000e-002 actualΔ=+9.728463e-003 u_a/u_g=+1.264158e+000
gc 67 @191.083s 0%: 0.076+40+0.38 ms clock, 0.60+21/79/117+3.0 ms cpu, 392->393->203 MB, 401 MB goal, 8 P
pacer: sweep done at heap size 204MB; allocated 0MB of spans; swept 51421 pages
pacer: assist ratio=+4.648241e+000 (scan 46 MB in 393->403 MB) workers=2+0
pacer: H_m_prev=213329416 h_t=+9.500000e-001 H_T=412687719 h_a=+9.410788e-001 H_a=414089208 h_g=+1.000000e+000 H_g=426658832 u_a=+3.187391e-001 u_g=+2.500000e-001 W_a=44303312 goalΔ=+5.000000e-002 actualΔ=-8.921194e-003 u_a/u_g=+1.274956e+000
gc 68 @195.883s 0%: 0.13+35+0.33 ms clock, 1.1+19/68/125+2.6 ms cpu, 393->394->211 MB, 403 MB goal, 8 P
pacer: sweep done at heap size 212MB; allocated 1MB of spans; swept 51551 pages
pacer: assist ratio=+4.491914e+000 (scan 47 MB in 411->422 MB) workers=2+0
pacer: H_m_prev=222200856 h_t=+9.500000e-001 H_T=431471305 h_a=+9.452341e-001 H_a=432232688 h_g=+1.000000e+000 H_g=444401712 u_a=+2.552427e-001 u_g=+2.500000e-001 W_a=44299704 goalΔ=+5.000000e-002 actualΔ=-4.765874e-003 u_a/u_g=+1.020971e+000
gc 69 @201.986s 0%: 0.050+43+0.35 ms clock, 0.40+1.8/71/127+2.8 ms cpu, 411->412->211 MB, 422 MB goal, 8 P
pacer: sweep done at heap size 215MB; allocated 3MB of spans; swept 53505 pages
pacer: assist ratio=+4.494443e+000 (scan 47 MB in 412->423 MB) workers=2+0
pacer: H_m_prev=222206456 h_t=+9.500000e-001 H_T=432531169 h_a=+9.771465e-001 H_a=439334712 h_g=+1.000000e+000 H_g=444412912 u_a=+3.360555e-001 u_g=+2.500000e-001 W_a=44342696 goalΔ=+5.000000e-002 actualΔ=+2.714648e-002 u_a/u_g=+1.344222e+000
gc 70 @207.689s 0%: 0.054+47+0.91 ms clock, 0.37+32/93/112+6.4 ms cpu, 412->418->217 MB, 423 MB goal, 8 P
pacer: sweep done at heap size 226MB; allocated 8MB of spans; swept 54363 pages
pacer: assist ratio=+4.520291e+000 (scan 47 MB in 412->423 MB) workers=2+0
pacer: H_m_prev=228344632 h_t=+9.500000e-001 H_T=432828427 h_a=+8.998711e-001 H_a=433825360 h_g=+1.000000e+000 H_g=456689264 u_a=+7.337997e-001 u_g=+2.500000e-001 W_a=44880032 goalΔ=+5.000000e-002 actualΔ=-5.012893e-002 u_a/u_g=+2.935199e+000
gc 71 @212.513s 0%: 0.88+61+0.43 ms clock, 3.5+242/115/0.056+1.7 ms cpu, 412->413->186 MB, 423 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 9MB of spans; swept 53936 pages
pacer: assist ratio=+5.844306e+000 (scan 54 MB in 362->371 MB) workers=2+0
pacer: H_m_prev=195236512 h_t=+9.500000e-001 H_T=380298687 h_a=+9.664850e-001 H_a=383929680 h_g=+1.000000e+000 H_g=390473024 u_a=+3.809236e-001 u_g=+2.500000e-001 W_a=44329704 goalΔ=+5.000000e-002 actualΔ=+1.648504e-002 u_a/u_g=+1.523694e+000
gc 72 @215.768s 0%: 12+75+1.9 ms clock, 99+92/144/167+15 ms cpu, 362->366->178 MB, 371 MB goal, 8 P
pacer: sweep done at heap size 182MB; allocated 3MB of spans; swept 47439 pages
pacer: assist ratio=+5.277034e+000 (scan 46 MB in 341->350 MB) workers=2+0
pacer: H_m_prev=186939816 h_t=+9.500000e-001 H_T=358247666 h_a=+9.170248e-001 H_a=358368264 h_g=+1.000000e+000 H_g=373879632 u_a=+2.544593e-001 u_g=+2.500000e-001 W_a=44319520 goalΔ=+5.000000e-002 actualΔ=-3.297520e-002 u_a/u_g=+1.017837e+000
gc 73 @220.494s 0%: 0.066+47+0.53 ms clock, 0.46+1.6/83/170+3.7 ms cpu, 341->341->182 MB, 350 MB goal, 8 P
pacer: sweep done at heap size 183MB; allocated 0MB of spans; swept 44608 pages
pacer: assist ratio=+5.121531e+000 (scan 46 MB in 355->364 MB) workers=2+0
pacer: H_m_prev=191136312 h_t=+9.500000e-001 H_T=372715808 h_a=+9.547069e-001 H_a=373615464 h_g=+1.000000e+000 H_g=382272624 u_a=+2.500165e-001 u_g=+2.500000e-001 W_a=44452496 goalΔ=+5.000000e-002 actualΔ=+4.706880e-003 u_a/u_g=+1.000066e+000
gc 74 @225.786s 0%: 0.078+52+0.35 ms clock, 0.62+0.006/95/194+2.8 ms cpu, 355->356->183 MB, 364 MB goal, 8 P
pacer: sweep done at heap size 186MB; allocated 2MB of spans; swept 46336 pages
pacer: assist ratio=+5.386511e+000 (scan 46 MB in 356->365 MB) workers=2+0
pacer: H_m_prev=192058472 h_t=+9.500000e-001 H_T=373400196 h_a=+9.611221e-001 H_a=376650120 h_g=+1.000000e+000 H_g=384116944 u_a=+3.111230e-001 u_g=+2.500000e-001 W_a=44349728 goalΔ=+5.000000e-002 actualΔ=+1.112213e-002 u_a/u_g=+1.244492e+000
gc 75 @230.281s 0%: 11+44+0.50 ms clock, 95+27/81/138+4.0 ms cpu, 356->359->188 MB, 365 MB goal, 8 P
pacer: sweep done at heap size 188MB; allocated 0MB of spans; swept 46772 pages
pacer: assist ratio=+5.156852e+000 (scan 46 MB in 363->372 MB) workers=2+0
pacer: H_m_prev=197524568 h_t=+9.500000e-001 H_T=380427075 h_a=+9.299823e-001 H_a=381218928 h_g=+1.000000e+000 H_g=395049136 u_a=+3.045377e-001 u_g=+2.500000e-001 W_a=44384232 goalΔ=+5.000000e-002 actualΔ=-2.001766e-002 u_a/u_g=+1.218151e+000
gc 76 @234.987s 0%: 0.063+42+0.40 ms clock, 0.50+18/83/104+3.2 ms cpu, 363->363->194 MB, 372 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 0MB of spans; swept 47450 pages
pacer: assist ratio=+4.842870e+000 (scan 47 MB in 379->388 MB) workers=2+0
pacer: H_m_prev=203889720 h_t=+9.500000e-001 H_T=397438189 h_a=+9.495958e-001 H_a=397502544 h_g=+1.000000e+000 H_g=407779440 u_a=+3.834952e-001 u_g=+2.500000e-001 W_a=44318328 goalΔ=+5.000000e-002 actualΔ=-4.041891e-004 u_a/u_g=+1.533981e+000
gc 77 @240.598s 0%: 0.33+30+0.35 ms clock, 2.3+32/59/128+2.4 ms cpu, 379->379->194 MB, 388 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 0MB of spans; swept 49340 pages
pacer: assist ratio=+4.750686e+000 (scan 46 MB in 379->389 MB) workers=2+0
pacer: H_m_prev=204176856 h_t=+9.500000e-001 H_T=398144869 h_a=+9.591589e-001 H_a=400014896 h_g=+1.000000e+000 H_g=408353712 u_a=+2.805263e-001 u_g=+2.500000e-001 W_a=44295912 goalΔ=+5.000000e-002 actualΔ=+9.158858e-003 u_a/u_g=+1.122105e+000
gc 78 @245.383s 0%: 0.16+41+0.35 ms clock, 1.2+10/83/96+2.8 ms cpu, 379->381->202 MB, 389 MB goal, 8 P
pacer: sweep done at heap size 202MB; allocated 0MB of spans; swept 49620 pages
pacer: assist ratio=+4.675879e+000 (scan 47 MB in 392->402 MB) workers=2+0
pacer: H_m_prev=212698192 h_t=+9.500000e-001 H_T=411595906 h_a=+9.354488e-001 H_a=411666464 h_g=+1.000000e+000 H_g=425396384 u_a=+3.820523e-001 u_g=+2.500000e-001 W_a=44310808 goalΔ=+5.000000e-002 actualΔ=-1.455118e-002 u_a/u_g=+1.528209e+000
gc 79 @251.096s 0%: 0.33+25+0.32 ms clock, 2.6+26/50/108+2.5 ms cpu, 392->392->202 MB, 402 MB goal, 8 P
pacer: sweep done at heap size 202MB; allocated 0MB of spans; swept 51243 pages
pacer: assist ratio=+4.777826e+000 (scan 46 MB in 394->404 MB) workers=2+0
pacer: H_m_prev=211935272 h_t=+9.500000e-001 H_T=413273780 h_a=+9.646603e-001 H_a=416380824 h_g=+1.000000e+000 H_g=423870544 u_a=+2.910651e-001 u_g=+2.500000e-001 W_a=44370120 goalΔ=+5.000000e-002 actualΔ=+1.466034e-002 u_a/u_g=+1.164261e+000
gc 80 @255.981s 0%: 0.050+44+0.33 ms clock, 0.40+14/79/128+2.6 ms cpu, 394->397->212 MB, 404 MB goal, 8 P
pacer: sweep done at heap size 213MB; allocated 0MB of spans; swept 51799 pages
pacer: assist ratio=+4.507685e+000 (scan 47 MB in 410->421 MB) workers=2+0
pacer: H_m_prev=223208504 h_t=+9.500000e-001 H_T=430708137 h_a=+9.399274e-001 H_a=433008288 h_g=+1.000000e+000 H_g=446417008 u_a=+3.238471e-001 u_g=+2.500000e-001 W_a=44397816 goalΔ=+5.000000e-002 actualΔ=-1.007262e-002 u_a/u_g=+1.295388e+000
gc 81 @262.082s 0%: 0.28+36+0.60 ms clock, 2.2+21/72/107+4.8 ms cpu, 410->412->212 MB, 421 MB goal, 8 P
pacer: sweep done at heap size 213MB; allocated 0MB of spans; swept 53583 pages
pacer: assist ratio=+4.520075e+000 (scan 47 MB in 410->421 MB) workers=2+0
pacer: H_m_prev=223065000 h_t=+9.500000e-001 H_T=430919580 h_a=+9.733560e-001 H_a=440186648 h_g=+1.000000e+000 H_g=446130000 u_a=+2.972738e-001 u_g=+2.500000e-001 W_a=44373416 goalΔ=+5.000000e-002 actualΔ=+2.335596e-002 u_a/u_g=+1.189095e+000
gc 82 @267.688s 0%: 0.21+34+0.61 ms clock, 1.4+13/68/137+4.3 ms cpu, 410->419->221 MB, 421 MB goal, 8 P
pacer: sweep done at heap size 226MB; allocated 4MB of spans; swept 54438 pages
pacer: assist ratio=+4.519006e+000 (scan 48 MB in 416->426 MB) workers=2+0
pacer: H_m_prev=232565800 h_t=+9.500000e-001 H_T=436339332 h_a=+8.799768e-001 H_a=437218312 h_g=+1.000000e+000 H_g=465131600 u_a=+7.698582e-001 u_g=+2.500000e-001 W_a=44677184 goalΔ=+5.000000e-002 actualΔ=-7.002318e-002 u_a/u_g=+3.079433e+000
gc 83 @272.491s 0%: 0.079+31+14 ms clock, 0.31+131/58/0.063+56 ms cpu, 416->416->192 MB, 426 MB goal, 8 P
pacer: sweep done at heap size 204MB; allocated 12MB of spans; swept 54335 pages
pacer: assist ratio=+5.849724e+000 (scan 53 MB in 374->383 MB) workers=2+0
pacer: H_m_prev=201361440 h_t=+9.500000e-001 H_T=392477638 h_a=+9.551349e-001 H_a=393688784 h_g=+1.000000e+000 H_g=402722880 u_a=+3.525674e-001 u_g=+2.500000e-001 W_a=44366288 goalΔ=+5.000000e-002 actualΔ=+5.134926e-003 u_a/u_g=+1.410270e+000
gc 84 @275.985s 0%: 0.20+28+0.47 ms clock, 1.4+24/57/111+3.2 ms cpu, 374->375->177 MB, 383 MB goal, 8 P
pacer: sweep done at heap size 177MB; allocated 0MB of spans; swept 48636 pages
pacer: assist ratio=+5.428401e+000 (scan 46 MB in 345->354 MB) workers=2+0
pacer: H_m_prev=186069384 h_t=+9.500000e-001 H_T=362048871 h_a=+9.551624e-001 H_a=363795856 h_g=+1.000000e+000 H_g=372138768 u_a=+4.422955e-001 u_g=+2.500000e-001 W_a=44385960 goalΔ=+5.000000e-002 actualΔ=+5.162360e-003 u_a/u_g=+1.769182e+000
gc 85 @280.883s 0%: 0.12+33+0.32 ms clock, 1.0+51/65/82+2.5 ms cpu, 345->346->182 MB, 354 MB goal, 8 P
pacer: sweep done at heap size 183MB; allocated 0MB of spans; swept 45140 pages
pacer: assist ratio=+5.137105e+000 (scan 46 MB in 354->363 MB) workers=2+0
pacer: H_m_prev=191682440 h_t=+9.500000e-001 H_T=371561782 h_a=+9.598619e-001 H_a=375671104 h_g=+1.000000e+000 H_g=383364880 u_a=+2.501529e-001 u_g=+2.500000e-001 W_a=44365000 goalΔ=+5.000000e-002 actualΔ=+9.861863e-003 u_a/u_g=+1.000611e+000
gc 86 @286.086s 0%: 0.18+28+0.46 ms clock, 1.3+0.035/56/123+3.2 ms cpu, 354->358->185 MB, 363 MB goal, 8 P
pacer: sweep done at heap size 189MB; allocated 3MB of spans; swept 46593 pages
pacer: assist ratio=+5.374278e+000 (scan 46 MB in 355->363 MB) workers=2+0
pacer: H_m_prev=194716168 h_t=+9.500000e-001 H_T=372058471 h_a=+9.234704e-001 H_a=374530784 h_g=+1.000000e+000 H_g=389432336 u_a=+3.021450e-001 u_g=+2.500000e-001 W_a=44462400 goalΔ=+5.000000e-002 actualΔ=-2.652961e-002 u_a/u_g=+1.208580e+000
gc 87 @290.582s 0%: 0.15+38+0.31 ms clock, 1.2+16/77/104+2.5 ms cpu, 355->357->189 MB, 363 MB goal, 8 P
pacer: sweep done at heap size 189MB; allocated 0MB of spans; swept 46651 pages
pacer: assist ratio=+5.041842e+000 (scan 46 MB in 366->375 MB) workers=2+0
pacer: H_m_prev=198485496 h_t=+9.500000e-001 H_T=383927185 h_a=+9.448657e-001 H_a=386027632 h_g=+1.000000e+000 H_g=396970992 u_a=+3.245972e-001 u_g=+2.500000e-001 W_a=44421456 goalΔ=+5.000000e-002 actualΔ=-5.134306e-003 u_a/u_g=+1.298389e+000
gc 88 @295.383s 0%: 0.20+48+0.61 ms clock, 1.6+29/95/80+4.9 ms cpu, 366->368->195 MB, 375 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 0MB of spans; swept 48049 pages
scvg1: inuse: 352, idle: 74, sys: 426, released: 0, consumed: 426 (MB)
pacer: assist ratio=+5.034171e+000 (scan 46 MB in 377->386 MB) workers=2+0
pacer: H_m_prev=204474696 h_t=+9.500000e-001 H_T=395536143 h_a=+9.453079e-001 H_a=397766240 h_g=+1.000000e+000 H_g=408949392 u_a=+3.394192e-001 u_g=+2.500000e-001 W_a=44356144 goalΔ=+5.000000e-002 actualΔ=-4.692107e-003 u_a/u_g=+1.357677e+000
gc 89 @300.982s 0%: 0.16+40+0.33 ms clock, 1.2+28/66/84+2.7 ms cpu, 377->379->195 MB, 386 MB goal, 8 P
pacer: sweep done at heap size 196MB; allocated 0MB of spans; swept 49314 pages
pacer: assist ratio=+4.765552e+000 (scan 46 MB in 378->388 MB) workers=2+0
pacer: H_m_prev=205331800 h_t=+9.500000e-001 H_T=397390812 h_a=+9.517837e-001 H_a=400763264 h_g=+1.000000e+000 H_g=410663600 u_a=+2.500158e-001 u_g=+2.500000e-001 W_a=44414400 goalΔ=+5.000000e-002 actualΔ=+1.783718e-003 u_a/u_g=+1.000063e+000
gc 90 @305.767s 0%: 0.091+54+0.53 ms clock, 0.73+0.006/106/209+4.2 ms cpu, 378->382->202 MB, 388 MB goal, 8 P
pacer: sweep done at heap size 202MB; allocated 0MB of spans; swept 49708 pages
pacer: assist ratio=+4.720519e+000 (scan 47 MB in 388->398 MB) workers=2+0
pacer: H_m_prev=211942440 h_t=+9.500000e-001 H_T=407442110 h_a=+9.241031e-001 H_a=407799112 h_g=+1.000000e+000 H_g=423884880 u_a=+3.809913e-001 u_g=+2.500000e-001 W_a=44388264 goalΔ=+5.000000e-002 actualΔ=-2.589687e-002 u_a/u_g=+1.523965e+000
gc 91 @311.385s 0%: 0.094+32+0.36 ms clock, 0.66+33/63/92+2.5 ms cpu, 388->388->202 MB, 398 MB goal, 8 P
pacer: sweep done at heap size 202MB; allocated 0MB of spans; swept 50753 pages
pacer: assist ratio=+4.742931e+000 (scan 46 MB in 395->405 MB) workers=2+0
pacer: H_m_prev=212702296 h_t=+9.500000e-001 H_T=414727809 h_a=+9.599312e-001 H_a=416881872 h_g=+1.000000e+000 H_g=425404592 u_a=+3.170202e-001 u_g=+2.500000e-001 W_a=44302536 goalΔ=+5.000000e-002 actualΔ=+9.931227e-003 u_a/u_g=+1.268081e+000
gc 92 @316.282s 0%: 0.17+37+0.33 ms clock, 1.4+20/74/78+2.6 ms cpu, 395->397->212 MB, 405 MB goal, 8 P
pacer: sweep done at heap size 212MB; allocated 0MB of spans; swept 51852 pages
pacer: assist ratio=+4.484210e+000 (scan 47 MB in 411->422 MB) workers=2+0
pacer: H_m_prev=222762960 h_t=+9.500000e-001 H_T=431500836 h_a=+9.452460e-001 H_a=433328752 h_g=+1.000000e+000 H_g=445525920 u_a=+4.213537e-001 u_g=+2.500000e-001 W_a=44332368 goalΔ=+5.000000e-002 actualΔ=-4.754022e-003 u_a/u_g=+1.685415e+000
gc 93 @322.384s 0%: 0.073+33+0.47 ms clock, 0.58+46/65/93+3.8 ms cpu, 411->413->212 MB, 422 MB goal, 8 P
pacer: sweep done at heap size 213MB; allocated 0MB of spans; swept 53606 pages
pacer: assist ratio=+4.474641e+000 (scan 47 MB in 412->422 MB) workers=2+0
pacer: H_m_prev=223212056 h_t=+9.500000e-001 H_T=432309571 h_a=+9.842751e-001 H_a=442914128 h_g=+1.000000e+000 H_g=446424112 u_a=+3.232358e-001 u_g=+2.500000e-001 W_a=44365264 goalΔ=+5.000000e-002 actualΔ=+3.427511e-002 u_a/u_g=+1.292943e+000
gc 94 @327.783s 0%: 0.058+41+0.37 ms clock, 0.46+24/78/77+2.9 ms cpu, 412->422->224 MB, 422 MB goal, 8 P
pacer: sweep done at heap size 234MB; allocated 9MB of spans; swept 54773 pages
pacer: assist ratio=+4.630858e+000 (scan 49 MB in 418->429 MB) workers=2+0
pacer: H_m_prev=235402600 h_t=+9.500000e-001 H_T=439247172 h_a=+8.691312e-001 H_a=439998336 h_g=+1.000000e+000 H_g=470805200 u_a=+8.319753e-001 u_g=+2.500000e-001 W_a=44802040 goalΔ=+5.000000e-002 actualΔ=-8.086883e-002 u_a/u_g=+3.327901e+000
gc 95 @332.590s 0%: 0.063+36+0.69 ms clock, 0.44+169/65/0.38+4.8 ms cpu, 418->419->173 MB, 429 MB goal, 8 P
pacer: sweep done at heap size 183MB; allocated 9MB of spans; swept 54788 pages
pacer: assist ratio=+6.020524e+000 (scan 52 MB in 339->347 MB) workers=2+0
pacer: H_m_prev=182326960 h_t=+9.500000e-001 H_T=355537572 h_a=+9.636150e-001 H_a=358019960 h_g=+1.000000e+000 H_g=364653920 u_a=+3.310020e-001 u_g=+2.500000e-001 W_a=44347368 goalΔ=+5.000000e-002 actualΔ=+1.361504e-002 u_a/u_g=+1.324008e+000
gc 96 @335.882s 0%: 0.068+48+0.61 ms clock, 0.54+31/95/137+4.8 ms cpu, 339->341->178 MB, 347 MB goal, 8 P
pacer: sweep done at heap size 178MB; allocated 0MB of spans; swept 44291 pages
pacer: assist ratio=+5.338360e+000 (scan 46 MB in 343->352 MB) workers=2+0
pacer: H_m_prev=186739704 h_t=+9.500000e-001 H_T=360102927 h_a=+9.342544e-001 H_a=361202088 h_g=+1.000000e+000 H_g=373479408 u_a=+2.868287e-001 u_g=+2.500000e-001 W_a=44451616 goalΔ=+5.000000e-002 actualΔ=-1.574563e-002 u_a/u_g=+1.147315e+000
gc 97 @340.684s 0%: 0.11+34+0.33 ms clock, 0.92+10/68/108+2.6 ms cpu, 343->344->182 MB, 352 MB goal, 8 P
pacer: sweep done at heap size 182MB; allocated 0MB of spans; swept 44853 pages
pacer: assist ratio=+5.129534e+000 (scan 46 MB in 355->364 MB) workers=2+0
pacer: H_m_prev=191812040 h_t=+9.500000e-001 H_T=372794494 h_a=+9.561066e-001 H_a=375204792 h_g=+1.000000e+000 H_g=383624080 u_a=+3.151858e-001 u_g=+2.500000e-001 W_a=44422384 goalΔ=+5.000000e-002 actualΔ=+6.106572e-003 u_a/u_g=+1.260743e+000
gc 98 @345.984s 0%: 0.062+33+0.51 ms clock, 0.50+17/65/89+4.1 ms cpu, 355->357->183 MB, 364 MB goal, 8 P
pacer: sweep done at heap size 183MB; allocated 0MB of spans; swept 46540 pages
pacer: assist ratio=+5.062491e+000 (scan 45 MB in 354->363 MB) workers=2+0
pacer: H_m_prev=192571304 h_t=+9.500000e-001 H_T=371484157 h_a=+9.375040e-001 H_a=373107664 h_g=+1.000000e+000 H_g=385142608 u_a=+3.378300e-001 u_g=+2.500000e-001 W_a=44399592 goalΔ=+5.000000e-002 actualΔ=-1.249604e-002 u_a/u_g=+1.351320e+000
gc 99 @350.384s 0%: 0.062+38+0.49 ms clock, 0.50+27/76/87+3.9 ms cpu, 354->355->188 MB, 363 MB goal, 8 P
pacer: sweep done at heap size 188MB; allocated 0MB of spans; swept 46416 pages
pacer: assist ratio=+5.145076e+000 (scan 46 MB in 365->374 MB) workers=2+0
pacer: H_m_prev=197793800 h_t=+9.500000e-001 H_T=383145266 h_a=+9.487374e-001 H_a=385448176 h_g=+1.000000e+000 H_g=395587600 u_a=+3.267600e-001 u_g=+2.500000e-001 W_a=44402400 goalΔ=+5.000000e-002 actualΔ=-1.262598e-003 u_a/u_g=+1.307040e+000
gc 100 @355.182s 0%: 0.12+33+0.48 ms clock, 0.96+21/66/98+3.8 ms cpu, 365->367->195 MB, 374 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 0MB of spans; swept 48018 pages
pacer: assist ratio=+4.880944e+000 (scan 46 MB in 377->387 MB) workers=2+0
pacer: H_m_prev=204592520 h_t=+9.500000e-001 H_T=395708149 h_a=+9.433983e-001 H_a=397604752 h_g=+1.000000e+000 H_g=409185040 u_a=+4.674016e-001 u_g=+2.500000e-001 W_a=44322240 goalΔ=+5.000000e-002 actualΔ=-6.601717e-003 u_a/u_g=+1.869607e+000
gc 101 @360.782s 0%: 0.32+35+0.55 ms clock, 2.5+62/65/88+4.4 ms cpu, 377->379->195 MB, 387 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 0MB of spans; swept 49354 pages
pacer: assist ratio=+4.771772e+000 (scan 46 MB in 377->387 MB) workers=2+0
pacer: H_m_prev=204609496 h_t=+9.500000e-001 H_T=395996874 h_a=+9.392818e-001 H_a=396795464 h_g=+1.000000e+000 H_g=409218992 u_a=+2.999972e-001 u_g=+2.500000e-001 W_a=44414352 goalΔ=+5.000000e-002 actualΔ=-1.071824e-002 u_a/u_g=+1.199989e+000
gc 102 @365.484s 0%: 0.099+33+0.34 ms clock, 0.79+13/65/114+2.7 ms cpu, 377->378->202 MB, 387 MB goal, 8 P
pacer: sweep done at heap size 202MB; allocated 0MB of spans; swept 49255 pages
pacer: assist ratio=+4.822795e+000 (scan 47 MB in 393->403 MB) workers=2+0
pacer: H_m_prev=211996392 h_t=+9.500000e-001 H_T=412378293 h_a=+9.557537e-001 H_a=414612736 h_g=+1.000000e+000 H_g=423992784 u_a=+2.799242e-001 u_g=+2.500000e-001 W_a=44295872 goalΔ=+5.000000e-002 actualΔ=+5.753738e-003 u_a/u_g=+1.119697e+000
gc 103 @371.283s 0%: 0.16+38+0.35 ms clock, 1.2+9.3/76/83+2.8 ms cpu, 393->395->203 MB, 403 MB goal, 8 P
pacer: sweep done at heap size 203MB; allocated 0MB of spans; swept 51612 pages
pacer: assist ratio=+4.748146e+000 (scan 46 MB in 394->404 MB) workers=2+0
pacer: H_m_prev=213502656 h_t=+9.500000e-001 H_T=413177263 h_a=+9.407605e-001 H_a=414357528 h_g=+1.000000e+000 H_g=427005312 u_a=+2.710910e-001 u_g=+2.500000e-001 W_a=44386376 goalΔ=+5.000000e-002 actualΔ=-9.239469e-003 u_a/u_g=+1.084364e+000
gc 104 @376.085s 0%: 0.11+47+2.5 ms clock, 0.93+8.3/78/135+20 ms cpu, 394->395->212 MB, 404 MB goal, 8 P
pacer: sweep done at heap size 212MB; allocated 0MB of spans; swept 51588 pages
pacer: assist ratio=+4.486245e+000 (scan 47 MB in 412->423 MB) workers=2+0
pacer: H_m_prev=222420072 h_t=+9.500000e-001 H_T=432548251 h_a=+9.455626e-001 H_a=432732184 h_g=+1.000000e+000 H_g=444840144 u_a=+3.717892e-001 u_g=+2.500000e-001 W_a=44368504 goalΔ=+5.000000e-002 actualΔ=-4.437353e-003 u_a/u_g=+1.487157e+000
gc 105 @382.193s 0%: 0.24+37+0.32 ms clock, 1.9+36/69/98+2.6 ms cpu, 412->412->211 MB, 423 MB goal, 8 P
pacer: sweep done at heap size 212MB; allocated 0MB of spans; swept 53556 pages
pacer: assist ratio=+4.505554e+000 (scan 47 MB in 413->423 MB) workers=2+0
pacer: H_m_prev=222158312 h_t=+9.500000e-001 H_T=433208708 h_a=+9.878325e-001 H_a=441613520 h_g=+1.000000e+000 H_g=444316624 u_a=+4.037878e-001 u_g=+2.500000e-001 W_a=44386400 goalΔ=+5.000000e-002 actualΔ=+3.783253e-002 u_a/u_g=+1.615151e+000
gc 106 @387.693s 0%: 0.11+30+0.65 ms clock, 0.80+37/59/94+4.5 ms cpu, 413->421->222 MB, 423 MB goal, 8 P
pacer: sweep done at heap size 222MB; allocated 0MB of spans; swept 54569 pages
pacer: assist ratio=+4.137043e+000 (scan 49 MB in 417->429 MB) workers=2+0
pacer: H_m_prev=232827080 h_t=+9.444474e-001 H_T=437714485 h_a=+8.820294e-001 H_a=438187408 h_g=+1.000000e+000 H_g=465654160 u_a=+7.817226e-001 u_g=+2.500000e-001 W_a=44940064 goalΔ=+5.555263e-002 actualΔ=-6.241798e-002 u_a/u_g=+3.126890e+000
gc 107 @392.521s 0%: 0.32+38+0.40 ms clock, 1.2+163/74/6.5+1.6 ms cpu, 417->417->172 MB, 429 MB goal, 8 P
pacer: sweep done at heap size 176MB; allocated 3MB of spans; swept 54565 pages
pacer: assist ratio=+6.367981e+000 (scan 54 MB in 336->344 MB) workers=2+0
pacer: H_m_prev=180789760 h_t=+9.500000e-001 H_T=352540032 h_a=+9.509152e-001 H_a=352705488 h_g=+1.000000e+000 H_g=361579520 u_a=+3.201814e-001 u_g=+2.500000e-001 W_a=44399024 goalΔ=+5.000000e-002 actualΔ=+9.151846e-004 u_a/u_g=+1.280726e+000
gc 108 @416.405s 0%: 0.073+32+0.39 ms clock, 0.59+18/63/97+3.1 ms cpu, 336->336->174 MB, 344 MB goal, 8 P
pacer: sweep done at heap size 174MB; allocated 0MB of spans; swept 43665 pages
scvg2: inuse: 314, idle: 118, sys: 432, released: 0, consumed: 432 (MB)
pacer: assist ratio=+5.604467e+000 (scan 48 MB in 339->348 MB) workers=2+0
pacer: H_m_prev=182602168 h_t=+9.500000e-001 H_T=356074227 h_a=+9.529513e-001 H_a=356613136 h_g=+1.000000e+000 H_g=365204336 u_a=+2.500494e-001 u_g=+2.500000e-001 W_a=44412864 goalΔ=+5.000000e-002 actualΔ=+2.951271e-003 u_a/u_g=+1.000198e+000
gc 109 @456.607s 0%: 0.14+35+0.37 ms clock, 1.1+0.014/60/132+2.9 ms cpu, 339->340->180 MB, 348 MB goal, 8 P
pacer: sweep done at heap size 180MB; allocated 0MB of spans; swept 44240 pages
pacer: assist ratio=+5.427288e+000 (scan 48 MB in 351->360 MB) workers=2+0
pacer: H_m_prev=189240312 h_t=+9.500000e-001 H_T=368444060 h_a=+9.477639e-001 H_a=368595456 h_g=+1.000000e+000 H_g=378480624 u_a=+3.016486e-001 u_g=+2.500000e-001 W_a=44417952 goalΔ=+5.000000e-002 actualΔ=-2.236058e-003 u_a/u_g=+1.206594e+000
gc 110 @501.105s 0%: 0.051+34+0.34 ms clock, 0.41+14/57/105+2.7 ms cpu, 351->351->181 MB, 360 MB goal, 8 P
pacer: sweep done at heap size 181MB; allocated 0MB of spans; swept 45823 pages
pacer: assist ratio=+5.400719e+000 (scan 49 MB in 353->363 MB) workers=2+0
pacer: H_m_prev=190353400 h_t=+9.500000e-001 H_T=371189130 h_a=+9.505685e-001 H_a=371297344 h_g=+1.000000e+000 H_g=380706800 u_a=+3.017230e-001 u_g=+2.500000e-001 W_a=44420448 goalΔ=+5.000000e-002 actualΔ=+5.684900e-004 u_a/u_g=+1.206892e+000
gc 111 @542.806s 0%: 0.052+31+0.31 ms clock, 0.41+13/62/151+2.5 ms cpu, 353->354->183 MB, 363 MB goal, 8 P
pacer: sweep done at heap size 184MB; allocated 0MB of spans; swept 46032 pages


pacer: assist ratio=+5.440812e+000 (scan 49 MB in 358->367 MB) workers=2+0
pacer: H_m_prev=192927560 h_t=+9.500000e-001 H_T=376208742 h_a=+9.560302e-001 H_a=377372128 h_g=+1.000000e+000 H_g=385855120 u_a=+3.611183e-001 u_g=+2.500000e-001 W_a=44454304 goalΔ=+5.000000e-002 actualΔ=+6.030170e-003 u_a/u_g=+1.444473e+000
gc 112 @571.005s 0%: 0.071+33+0.40 ms clock, 0.56+30/66/106+3.2 ms cpu, 358->359->188 MB, 367 MB goal, 8 P
pacer: sweep done at heap size 188MB; allocated 0MB of spans; swept 46771 pages
pacer: assist ratio=+5.615165e+000 (scan 52 MB in 366->376 MB) workers=2+0
pacer: H_m_prev=197184024 h_t=+9.500000e-001 H_T=384508846 h_a=+9.560540e-001 H_a=385702600 h_g=+1.000000e+000 H_g=394368048 u_a=+2.510718e-001 u_g=+2.500000e-001 W_a=44439528 goalΔ=+5.000000e-002 actualΔ=+6.054006e-003 u_a/u_g=+1.004287e+000
gc 113 @588.075s 0%: 0.044+32+0.51 ms clock, 0.35+0.28/62/148+4.0 ms cpu, 366->367->188 MB, 376 MB goal, 8 P
pacer: sweep done at heap size 188MB; allocated 0MB of spans; swept 47854 pages
2016/06/08 01:53:31 [store_cassandra.go:328 Search()] [E] cassandra query error. gocql: no response received from cassandra within timeout period
scvg3: inuse: 327, idle: 105, sys: 432, released: 0, consumed: 432 (MB)
pacer: assist ratio=+5.577633e+000 (scan 52 MB in 365->375 MB) workers=2+0
pacer: H_m_prev=197271520 h_t=+9.500000e-001 H_T=383584765 h_a=+9.499444e-001 H_a=384668496 h_g=+1.000000e+000 H_g=394543040 u_a=+4.138444e-001 u_g=+2.500000e-001 W_a=44447440 goalΔ=+5.000000e-002 actualΔ=-5.559850e-005 u_a/u_g=+1.655377e+000
gc 114 @604.505s 0%: 0.080+36+0.40 ms clock, 0.64+48/60/107+3.2 ms cpu, 365->366->188 MB, 375 MB goal, 8 P
pacer: sweep done at heap size 189MB; allocated 0MB of spans; swept 47714 pages
pacer: assist ratio=+5.436388e+000 (scan 51 MB in 368->377 MB) workers=2+0
pacer: H_m_prev=198019504 h_t=+9.500000e-001 H_T=386055134 h_a=+9.550923e-001 H_a=387146408 h_g=+1.000000e+000 H_g=396039008 u_a=+4.391938e-001 u_g=+2.500000e-001 W_a=44445232 goalΔ=+5.000000e-002 actualΔ=+5.092302e-003 u_a/u_g=+1.756775e+000
gc 115 @619.274s 0%: 0.053+42+0.44 ms clock, 0.43+65/80/108+3.5 ms cpu, 368->369->194 MB, 377 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 1MB of spans; swept 48034 pages
pacer: assist ratio=+5.495903e+000 (scan 53 MB in 378->387 MB) workers=2+0
pacer: H_m_prev=203494544 h_t=+9.500000e-001 H_T=396346610 h_a=+9.504110e-001 H_a=396898000 h_g=+1.000000e+000 H_g=406989088 u_a=+4.484658e-001 u_g=+2.500000e-001 W_a=44439240 goalΔ=+5.000000e-002 actualΔ=+4.110145e-004 u_a/u_g=+1.793863e+000
gc 116 @636.324s 0%: 0.13+31+0.58 ms clock, 1.0+50/62/99+4.6 ms cpu, 378->378->193 MB, 387 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 1MB of spans; swept 49098 pages
pacer: assist ratio=+5.427672e+000 (scan 52 MB in 377->387 MB) workers=2+0
pacer: H_m_prev=203201224 h_t=+9.500000e-001 H_T=396242386 h_a=+9.544042e-001 H_a=397137320 h_g=+1.000000e+000 H_g=406402448 u_a=+3.963664e-001 u_g=+2.500000e-001 W_a=44462040 goalΔ=+5.000000e-002 actualΔ=+4.404172e-003 u_a/u_g=+1.585466e+000
gc 117 @653.207s 0%: 0.13+33+0.90 ms clock, 1.0+39/62/125+7.2 ms cpu, 377->378->194 MB, 387 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 1MB of spans; swept 49195 pages
pacer: assist ratio=+5.447622e+000 (scan 52 MB in 378->388 MB) workers=2+0
pacer: H_m_prev=203533648 h_t=+9.500000e-001 H_T=396691838 h_a=+9.536359e-001 H_a=397630632 h_g=+1.000000e+000 H_g=407067296 u_a=+2.907894e-001 u_g=+2.500000e-001 W_a=44464232 goalΔ=+5.000000e-002 actualΔ=+3.635853e-003 u_a/u_g=+1.163157e+000
gc 118 @670.355s 0%: 0.080+33+0.36 ms clock, 0.64+11/65/101+2.9 ms cpu, 378->379->194 MB, 388 MB goal, 8 P
pacer: sweep done at heap size 195MB; allocated 1MB of spans; swept 49169 pages
pacer: assist ratio=+5.450855e+000 (scan 52 MB in 378->388 MB) workers=2+0
pacer: H_m_prev=203670000 h_t=+9.500000e-001 H_T=397156500 h_a=+9.532830e-001 H_a=397825152 h_g=+1.000000e+000 H_g=407340000 u_a=+7.601926e-001 u_g=+2.500000e-001 W_a=44460248 goalΔ=+5.000000e-002 actualΔ=+3.283017e-003 u_a/u_g=+3.040770e+000
gc 119 @687.005s 0%: 0.070+30+0.40 ms clock, 0.56+124/60/4.5+3.2 ms cpu, 378->379->194 MB, 388 MB goal, 8 P
pacer: sweep done at heap size 196MB; allocated 1MB of spans; swept 49166 pages
pacer: assist ratio=+5.294629e+000 (scan 51 MB in 380->389 MB) workers=2+0
pacer: H_m_prev=204420944 h_t=+9.500000e-001 H_T=398620840 h_a=+9.570002e-001 H_a=400051832 h_g=+1.000000e+000 H_g=408841888 u_a=+2.510281e-001 u_g=+2.500000e-001 W_a=44457688 goalΔ=+5.000000e-002 actualΔ=+7.000218e-003 u_a/u_g=+1.004113e+000
gc 120 @701.215s 0%: 0.055+33+0.33 ms clock, 0.44+0.27/64/153+2.7 ms cpu, 380->381->201 MB, 389 MB goal, 8 P
pacer: sweep done at heap size 202MB; allocated 0MB of spans; swept 49464 pages
pacer: assist ratio=+5.269568e+000 (scan 53 MB in 392->402 MB) workers=2+0
pacer: H_m_prev=211172784 h_t=+9.500000e-001 H_T=411421124 h_a=+9.525614e-001 H_a=412327824 h_g=+1.000000e+000 H_g=422345568 u_a=+3.438938e-001 u_g=+2.500000e-001 W_a=44454368 goalΔ=+5.000000e-002 actualΔ=+2.561387e-003 u_a/u_g=+1.375575e+000
gc 121 @718.855s 0%: 0.055+30+0.78 ms clock, 0.44+23/59/127+6.2 ms cpu, 392->393->201 MB, 402 MB goal, 8 P
pacer: sweep done at heap size 202MB; allocated 1MB of spans; swept 51108 pages
2016/06/08 01:55:40 INF    1 [metrics/tank] stopping...
2016/06/08 01:55:40 [I] Shutting down
2016/06/08 01:55:40 INF    1 [metrics/tank] (nsqd:4150) received CLOSE_WAIT from nsqd
2016/06/08 01:55:40 INF    1 [metrics/tank] (nsqd:4150) beginning close
2016/06/08 01:55:40 INF    1 [metrics/tank] (nsqd:4150) readLoop exiting
2016/06/08 01:55:40 INF    1 [metrics/tank] (nsqd:4150) breaking out of writeLoop
2016/06/08 01:55:40 INF    1 [metrics/tank] (nsqd:4150) writeLoop exiting
2016/06/08 01:55:40 INF    1 [metrics/tank] (nsqd:4150) finished draining, cleanup exiting
2016/06/08 01:55:40 INF    1 [metrics/tank] (nsqd:4150) clean close complete
2016/06/08 01:55:40 WRN    1 [metrics/tank] there are 0 connections left alive
2016/06/08 01:55:40 INF    1 [metrics/tank] stopping handlers
2016/06/08 01:55:40 INF    1 [metrics/tank] rdyLoop exiting
2016/06/08 01:55:40 [I] closing store
2016/06/08 01:55:40 [I] terminating.