Go-ipfs: odd error message from dht code

[whyrusleeping]

18:51:46.315 ERROR        dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35

Got this on my node, havent really investigated much.

[Stebalien]

47 in ASCII is a forward slash (/). I'm guessing something is putting a string path where a binary CID should go.

[djdv]

I get this message twice every time I publish to IPNS, I'm publishing to a key that I'm pretty sure was generated as ed25519.

[Macil]

Yeah I get this message too from the ipfs daemon whenever I run "ipfs name publish ...something...". The ipfs-name-publish command just hangs without producing any output and I have to kill it with ctrl-c. Ipfs publish / ipns seems to be just broken for me.

(Using ipfs version 0.4.11)

[whyrusleeping]

@AgentME how long did it hang before you killed it? it should have a hard timeout at 30 seconds

[Macil]

Oh, I think I just didn't wait that long. I tried it now and it does eventually finish successfully. Whoops. I think I assumed the red error message in my ipfs daemon terminal happening at the same time was actually an error fatal to the request.

Is the command supposed to take a long time to run? I thought it would be quick like add. I've even seen it slightly over 30 seconds:

chris@canyon:~$ time ipfs name publish QmccqhJg5wm5kNjAP4k4HrYxoqaXUGNuotDUqfvYBx8jrR
Published to QmYDt3TopyRaiNNd3Swxew5ThMgNw8Kq2E3UpuR42JBDFF: /ipfs/QmccqhJg5wm5kNjAP4k4HrYxoqaXUGNuotDUqfvYBx8jrR

real    0m32.194s
user    0m0.048s
sys 0m0.008s
chris@canyon:~$ time ipfs name publish QmccqhJg5wm5kNjAP4k4HrYxoqaXUGNuotDUqfvYBx8jrR
Published to QmYDt3TopyRaiNNd3Swxew5ThMgNw8Kq2E3UpuR42JBDFF: /ipfs/QmccqhJg5wm5kNjAP4k4HrYxoqaXUGNuotDUqfvYBx8jrR

real    0m21.396s
user    0m0.024s
sys 0m0.008s

[whyrusleeping]

Its not supposed to take that long, but it is right now. We've identified some issues very recently in the dht handlers; Apparently some really overloaded nodes are taking forever to respond to requests, which causes clients to wait (like we're seeing here).

tracking issue: https://github.com/libp2p/go-libp2p-kad-dht/issues/88

[JayBrown]

Had the same error printed by daemon:

https://discuss.ipfs.io/t/v0-4-11-ipfs-publish-creates-error-webui-not-loading/1194

[aventrax]

Same here, ipfs 0.4.11, the daemon crashes and restarts after 1minute and few seconds (more or less).

[whyrusleeping]

@aventrax your daemon shouldnt be crashing. Do you have any other information? Stack traces or other log output?

[aventrax]

@whyrusleeping How can I provide you theese logs? I have the service starting as a normal user by systemd. I don't know where the logs are, probably under ~/.ipfs/ ?

[whyrusleeping]

@aventrax logs are printed out to stderr

[aventrax]

@whyrusleeping
$ ipfs daemon Initializing daemon... Adjusting current ulimit to 2048... Successfully raised file descriptor limit to 2048. Swarm listening on /ip4/127.0.0.1/tcp/4001 Swarm listening on /ip4/127.0.0.2/tcp/4001 Swarm listening on /ip4/81.x.x.x/tcp/4001 Swarm listening on /ip6/2a00:d880:x:x:x:x:x:x/tcp/4001 Swarm listening on /ip6/::1/tcp/4001 Swarm listening on /p2p-circuit/ipfs/QmRbxnuFSj3ZprgtRxxxxxxxxxxxxxxxxxxxx Swarm announcing /ip4/127.0.0.1/tcp/4001 Swarm announcing /ip4/127.0.0.2/tcp/4001 Swarm announcing /ip4/81.x.x.x/tcp/4001 Swarm announcing /ip6/2a00:d880:x:x:x:x:x:x/tcp/4001 Swarm announcing /ip6/::1/tcp/4001 API server listening on /ip4/127.0.0.1/tcp/5001 Gateway (readonly) server listening on /ip4/127.0.0.1/tcp/8080 Daemon is ready 16:06:47.715 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:06:47.715 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:06:53.181 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:06:53.181 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:06:57.802 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:06:57.802 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:07:03.273 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:07:03.273 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:07:07.903 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:07:07.904 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:08:18.254 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 16:08:18.254 ERROR dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35 Killed

[aventrax]

@whyrusleeping Using strace ipfs daemon I've got (cutting the first part..):

16:12:30.361 ERROR        dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35
16:12:30.379 ERROR        dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35
16:12:40.478 ERROR        dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35
16:12:40.485 ERROR        dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35
)   = ?
+++ killed by SIGKILL +++
Killed

[aventrax]

Inizializing ipfs with another user on the same VPS results the same. I'm thinking about hitting a limit on the vps, perhaps open files or something like this, because the daemon crashes after 200+ peers, it never crash before..

[7c]

I have added brand new vps, also that throws the mentioned error with invalid cid version number, running version 0.4.11 on ubuntu 64bit. I am also getting this in combination with ipfs name publish command.

[Stebalien]

So, this error isn't causing any bugs (it indicates that we're doing something fishy but it isn't likely to cause any problems, I think). According to c372d79e4264ebbb1ffb37cd96116f3d1a8f718a, we switched to switch to using CIDs as DHT keys. However, we didn't really; we just switched to CIDs for provider records. We still use paths for public keys and IPNS records.

This does bring up a good point... we should be consistent dammit! We now have a mix of unicode paths (/pk/Qm..., /ipns/Qm...) and binary CIDs ([0x1, 0x71, ...]). Technically, there's a non-zero probability that we'll parse one of these CIDs as a path and try to validate it (using the validator logic). I'd really like to avoid adding any magic to the validator logic to detect and throw away raw CIDs but that's the only backwards compatible way forward that I can see.

[ProIcons]

is there any update on this issue? It seems using ipfs version 0.4.11 on windows, can't publish anything.

While i tried the following...

C:\Users\Nikolas>ipfs key gen --type=rsa --size=2048 mykey
C:\Users\Nikolas>ipfs name publish --key=mykey /ipfs/...
Published to ...: /ipfs/...

It did said it was published after more than 1 minute.

Whatsoever i got the following errors on my daemon

19:42:46.955 ERROR        dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35
19:42:46.958 ERROR        dht: loggableKey could not cast key: invalid cid version number: 47 lookup.go:35

And i can't "ls" the new hash, can't access it through the http api. can't do anything.

Also

C:\Users\Nikolas>ipfs name resolve ...

Resolves that, after more than 2 minutes.

[Stebalien]

Not really. This is, effectively, just a noisy error message that you should ignore (although that's still a bug).

[whyrusleeping]

This should be demoted to a warning in the next release. (0.4.12)

[Stebalien]

@whyrusleeping would you like a PR for that? It's still an error.

[ProIcons]

I've updated my comment,

Also while browsing throught http api
i get this

19:48:57.572 ERROR core/serve: ipfs resolve -r /ipfs/...: Failed to get block for ...: context canceled gateway_handler.go:593

And still doesn't show anything, loads infinitely

[ProIcons]

Sorry my mistake, i got it working.

[JayBrown]

Still an ERROR in go-ipfs v0.4.13.

[ghost]

from zeb on irc:

16:02:30.545 ERROR        dht: loggableKey could not cast key: 2f706b2f122049a7da5f8f383fe86944fb89f47d5f66353d7dc58720fb3452917195077d7cc9 invalid cid version number: 47 lookup.go:35
16:02:30.552 ERROR        dht: loggableKey could not cast key: 2f69706e732f122049a7da5f8f383fe86944fb89f47d5f66353d7dc58720fb3452917195077d7cc9 invalid cid version number: 47 lookup.go:35

[matthewrobertbell]

I'm also getting the errors:

15:09:29.985 ERROR dht: loggableKey could not cast key: 2f706b2f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 15:09:29.991 ERROR dht: loggableKey could not cast key: 2f69706e732f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 19:09:29.989 ERROR dht: loggableKey could not cast key: 2f706b2f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 19:09:29.999 ERROR dht: loggableKey could not cast key: 2f69706e732f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 23:09:29.993 ERROR dht: loggableKey could not cast key: 2f706b2f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 23:09:30.005 ERROR dht: loggableKey could not cast key: 2f69706e732f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 03:09:29.992 ERROR dht: loggableKey could not cast key: 2f706b2f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 03:09:30.001 ERROR dht: loggableKey could not cast key: 2f69706e732f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 07:09:29.989 ERROR dht: loggableKey could not cast key: 2f706b2f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35 07:09:29.998 ERROR dht: loggableKey could not cast key: 2f69706e732f12202d29f6702ce593aaf89077ba4418b602d91e31fc83ccdfee98aa628dc82ab4fe invalid cid version number: 47 lookup.go:35

This is on a completely fresh linux 64 bit machine, 0.4.3, the only command run on the daemon has been "ipfs swarm peers" for monitoring purposes. The error times look regular, is this IPNS? Is IPNS published when there is nothing to publish?

[whyrusleeping]

@mattseh the likely root of the issue is someone else publishing an ipns entry with something that we don't recognize as a CID. this isnt really an error in that it causes incorrect daemon behaviour, but its something that we're not exactly handling properly.

[Stebalien]

@whyrusleeping the problem is that IPNS entries aren't CIDs (actually, I'm pretty sure that only provider records are CIDs). See https://github.com/ipfs/go-ipfs/issues/4237#issuecomment-335968403.