lockup while running `files cp`

[RubenKelevra]

Version information:

go-ipfs version: 0.9.0-dev-2ed925442
Repo version: 11
System version: amd64/linux
Golang version: go1.15.6

Description:

I have a script that had run successfully for 160 days, now I updated it to 0.8rc1 and had run the garbage collection and it seems that the garbage collection did damage the MFS.

When I run the following commands, the IPFS API call will just get stuck:

$ ipfs files rm /x86-64.archlinux.pkg.pacman.store/lastsync
$ ipfs cat bafykbzaceafqnjhgsdwwz3bm66y7ti7z6te4773vgh4pn4axiqoluxjgydmhc
1608780003
$ ipfs files cp /ipfs/bafykbzaceafqnjhgsdwwz3bm66y7ti7z6te4773vgh4pn4axiqoluxjgydmhc /x86-64.archlinux.pkg.pacman.store/lastsync

I aborted it after 3 minutes.

Btw: It would be nice if there would be a timeout for such operations, that it at least fails with a timeout itself,

[RubenKelevra]

It isn't a database issue, since the issue is fixed as soon as the daemon is restarted.

It happened again, this time I collected the debug information and killed it with sigabrt to get the stack trace. But it was too long for the system log.

Hope that's helpful.

debug_info.tar.gz

[gammazero]

@RubenKelevra We are looking into this, and I have a couple of questions.

1. When you reported, "It happened again, this time ...", Was this after another upgrade attempt, or during normal operation with ipfs daemon running?
2. Was GC running when you saw this?

If GC were to run between:
$ ipfs cat bafykbzaceafqnjhgsdwwz3bm66y7ti7z6te4773vgh4pn4axiqoluxjgydmhc
and
$ ipfs files cp ...
Then the block for bafykbzaceafqnjhgsdwwz3bm66y7ti7z6te4773vgh4pn4axiqoluxjgydmhc could have been removed, causing ipfs files cp ... to then try to reacquire it from the ipfs network, and waiting.

[RubenKelevra]

@RubenKelevra We are looking into this, and I have a couple of questions.

Thanks!

1. When you reported, "It happened again, this time ...", Was this after another upgrade attempt, or during normal operation with ipfs daemon running?

Normal operation. I've rebooted the machine because I did a minor kernel update.

2. Was GC running when you saw this?

GC isn't expected to run, since there's a lot of free space for ipfs configured. But auto-gc is on for running when there's 90% of storage filled.

---

The GC was run after upgrading the daemon was upgraded while the cluster daemon was turned off.

So no operation should have been running on the ipfs client.

After the update and the GC run the normal cluster operation is run again.

I can't say what exactly the cluster was doing at the time that this happened, but the daemon got stuck multiple times when this commands was run. So not sure how the block can disappear between both operations.

Tbh I think the MFS is corrupted since I'm now no longer able to start the daemon, see #7845.

I've removed the startup timeout (which was 15 minutes) which killed the daemon multiple times due to the timeout reached. Now the daemon won't start within 24 hours on a pretty high performance machine with a flatfs storage on a fast SSD.

If GC were to run between:
$ ipfs cat bafykbzaceafqnjhgsdwwz3bm66y7ti7z6te4773vgh4pn4axiqoluxjgydmhc
and
$ ipfs files cp ...
Then the block for bafykbzaceafqnjhgsdwwz3bm66y7ti7z6te4773vgh4pn4axiqoluxjgydmhc could have been removed, causing ipfs files cp ... to then try to reacquire it from the ipfs network, and waiting.

The network cannot provide this block, since I've just added this file with this content and try to move it in the MFS before recursively sharing the folder with it in it in the cluster.

[RubenKelevra]

I forgot to make clear that cat is always successful, even after the files cp operation got stuck I can successfully cat the file.

I see currently three possible scenarios:

• Both commands cannot agree if a block is locally available or not due to different code paths taken.

• They run on different threads which have different data (cached) about the availability of this block.

• The MFS cp operation is what actually get stuck creating the file, not the fetching of the block.

---

Edit:

Since IPFS runs on ZFS we can snapshot the current state and do some commands to try to work around this state.

Additionally its all publicly available data, so I'm happy to share the ipfs database and the flatfs content as a tar.gz when this helps the debugging efforts, too.

[gammazero]

So far, I have not been able to reproduce this problem. It does appear that the cause is that MFS is somehow corrupted, particularly given the related issues. At this point, I think it would be useful to get your db and flat fs content -- if possible a minimum dataset that still exhibits the problem. Hopefully, the nature of any corruption found will give some indication of the possible cause.

[RubenKelevra]

@gammazero wrote:

So far, I have not been able to reproduce this problem. It does appear that the cause is that MFS is somehow corrupted, particularly given the related issues. At this point, I think it would be useful to get your db and flat fs content -- if possible a minimum dataset that still exhibits the problem. Hopefully, the nature of any corruption found will give some indication of the possible cause.

I've packed the whole ipfs folder and just removed the key files and the identity from the config.

The server providing it is a bit slow, hope this works for you.

/ipfs/QmVx4BqSsQnhiYdnLbqA3zCXzteXBb7hvj6rQXDfyqxRJ8

[bqv]

Will pin to my cluster, to help deliver :)

[bqv]

@RubenKelevra could you see if you can get a gateway to see it? My node's been searching for yours for ages now

[RubenKelevra]

@bqv

@RubenKelevra could you see if you can get a gateway to see it? My node's been searching for yours for ages now

Just connect to the node, I guess with ipfs swarm connect <address>, since it is probably still in the providing step.

"Addresses": [
  "/ip4/94.176.233.122/tcp/443/p2p/QmVBVA4wNqXXqLWjft8WWf2YLNH2xdq2iCVjGS9dPtA6JJ",
  "/ip4/94.176.233.122/udp/443/quic/p2p/QmVBVA4wNqXXqLWjft8WWf2YLNH2xdq2iCVjGS9dPtA6JJ",
  "/ip6/2a02:7b40:5eb0:e97a::1/tcp/443/p2p/QmVBVA4wNqXXqLWjft8WWf2YLNH2xdq2iCVjGS9dPtA6JJ",
  "/ip6/2a02:7b40:5eb0:e97a::1/udp/443/quic/p2p/QmVBVA4wNqXXqLWjft8WWf2YLNH2xdq2iCVjGS9dPtA6JJ"
]

I'll also run ipfs dht provide manually on the root ids, so it should be available soon. :)

[bqv]

Got it. Pinned!