Re: number of keys reported by hockeypuck

[Gunnar Wolf]

Hello Andrew, list,

I hope I am not abusing the list to ask for Hockeypuck-related support.

Andrew Gallagher dijo [Tue, Sep 07, 2021 at 08:10:06PM +0100]:
> > My new hockypuck instance reports 0 keys, but when I go to the database 
> > directly
> > and query the number of keys I see 6 million+ keys.  Can anybody suggest 
> > what is
> > wrong ?
> 
> Hi, Skip.
> 
> It sounds like your ptree database has not been populated. After you
> restore the postgres database, you need to run `hockeypuck-pbuild` to
> generate the ptrees. After that it should return the correct number of
> keys (and sync correctly!).

I had the same issue as Skip, but with Andrew's help, I managed to get
my server (hkp.openpgpkeys.net, aliased as pgp.gwolf.org, as I
operated that keyserver in the past and there are some servers still
trying to sync with it) to start syncing last week. However, my
happiness lasted only for two days, as can be seen in the server's
statistics:

    https://hkp.openpgpkeys.net/pks/lookup?op=stats

I got 4425272 new keys on 2021.09.02, 1562088 on 2021.09.03, and
nothing afterwards. Every now and then, a third row appears with
today's date, showing a number of updated keys, but it ends up
rejecting them. I have the following in my logs:

First of all, I see many lines simliar to the following in the logs:

    time="2021-09-10T17:39:57Z" level=error msg="recon with 194.95.66.28:11370 
failed" 
error="[{/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/recon/gossip.go:115:
 } {/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/recon/peer.go:427: 
} {/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/recon/peer.go:373: 
} {/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/recon/peer.go:359: 
} 
{/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/recon/messages.go:144:
 } {read tcp 132.248.241.96:41648->194.95.66.28:11370: read: connection reset 
by peer}]" label="gossip :11370"

Sometimes, though, a reconciliation attempt does start to progress,
and I see lines increasing the size of the recover set, such as the
following:

    time="2021-09-08T16:09:56Z" level=info msg= POST="/pks/hashquery" 
duration=1.566869497s from="31.220.44.249:42062"
    time="2021-09-08T16:09:56Z" level=info msg="ReconRqstPoly: solved" 
label="gossip :11370" localSet={17513954546661128035079817349538381151, 
49879024575748961585423554984045044319} 
remoteSet={261125229682694284340418712624697891935}
    time="2021-09-08T16:09:56Z" level=info msg="recover set now 1 elements" 
label="gossip :11370"
    time="2021-09-08T16:09:56Z" level=info msg="ReconRqstPoly: low MBar" 
label="gossip :11370"
    time="2021-09-08T16:09:56Z" level=info msg="ReconRqstPoly: sending 
SyncFail" 
error="[{/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/recon/gossip.go:258:
 bs=0101111101 leaf=false size=6134} 
{/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/decode.go:289: } {low 
MBar}]" label="gossip :11370"
    time="2021-09-08T16:09:56Z" level=info msg="recover set now 1 elements" 
label="gossip :11370"
    time="2021-09-08T16:09:56Z" level=info msg="ReconRqstPoly: low MBar" 
label="gossip :11370"
    time="2021-09-08T16:09:56Z" level=info msg="ReconRqstPoly: sending 
SyncFail" 
error="[{/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/recon/gossip.go:258:
 bs=0101111110 leaf=false size=5954} 
{/home/gwolf/packaging/src/gopkg.in/hockeypuck/conflux.v2/decode.go:289: } {low 
MBar}]" label="gossip :11370"
    time="2021-09-08T16:09:56Z" level=info msg="recover set now 1 elements" 
label="gossip :11370"
    time="2021-09-08T16:09:56Z" level=info msg="ReconRqstPoly: low MBar" 
label="gossip :11370"

after which, the recover increases until several thousand elements, and seems 
to be successful:

    time="2021-09-08T16:10:39Z" level=info msg=ReconRqstFull label="gossip 
:11370" localNeeds=1 remoteNeeds=0
    time="2021-09-08T16:10:39Z" level=info msg="recover set now 4403 elements" 
label="gossip :11370"
    time="2021-09-08T16:10:39Z" level=info msg="recover set now 4403 elements" 
label="gossip :11370"
    time="2021-09-08T16:10:39Z" level=info msg="reconcilation done" 
label="gossip :11370"
    time="2021-09-08T16:10:39Z" level=info msg="recovered 4403 items" 
label="serve :11370"
    time="2021-09-08T16:10:39Z" level=info msg="waiting 36s for next gossip 
attempt" label="gossip :11370"

But it does not seem to enter my database. Just 30 minutes after the
log entries I pasted, my server recovered successfully(?) 7766 items
from the same peer.

So, any pointers on how to get this to work?

Thanks!