zlatinb / muwire

MuWire file sharing client for I2P
GNU General Public License v3.0
191 stars 27 forks source link

Loosing files #124

Closed JamesOlvertone closed 2 years ago

JamesOlvertone commented 2 years ago

Hello,

I add files to downloadlist. Exit muwire start muwire some files in the downloadlist do not appear. in incompletes-dir the missing files are still there as part+pied or only pieces (if never started downloading).

How can I reimport this files?

I do it manually extracting the hash from the filename, searching with this hash and adding the files again (if found).

Is there an easier way to add ALL files in the incomplete dir? Thats quite annoying.

This error happens not always but sometimes. Recognized it still 0.8.10 iirc, last version where it happened: 0.8.12-beta5

zlatinb commented 2 years ago

Hi,

I would rather find out why they're getting lost rather than try to recover after the fact. Can you help me with some more debugging? Here's what to look for

Also, approximately how many files are you sharing and which operating system?

Thanks

JamesOlvertone commented 2 years ago

What is hopeless state?

zlatinb commented 2 years ago

The download becomes Hopeless if it couldn't download even a single piece from all sources that it knows about after trying several times. With 0.8.10 it would happen more often but with 0.8.12-beta5 it should happen very rarely.

JamesOlvertone commented 2 years ago

I've never seen "hopeless" status on any file. The files that were first "lost" and manually added after, were found and downloaded after re-adding them.

This error seems to happen when a lot of files are added in the download list. After a restart most of them are "lost".

Right now where it happend there were ~250 files in the incomplete dir, most of them were added as new entries.

I'm going to set up a special setting for investigating in this behaviour. Thank you for the hints where to have a look on.

zlatinb commented 2 years ago

I think what's most likely happening is the downloads.json file gets corrupted. It should be easy to see if that's the case by opening it in an editor.

To detect any other errors, you can enable logging, but only if you are using the .zip distribution. Clone the source tree from GitHub, then copy the file logging/1_logging.properties as logging.properties in the current working directory from where you start MuWire. Add the following line to logging.properties at the bottom:

com.muwire.core.download.level = WARNING

Then start MuWire. If something goes wrong with downloads, a file called MuWire.log should appear in the current working directory.

JamesOlvertone commented 2 years ago

Ok here again: adding a new file, it does not appear in donwload.json, but appears in incompletes as .pieces after exiting muwire: still not in download.json starting muwire not in downloads.json adding again this file now it is in downloads.json.

Similar situation: delete a shared complete file in the library. It disappears automatically in the gui view for the libraray (autofolderwatch works like expected). Then search for this file and try to add it to download. It does not appear in the downloadlist, not in download.json but a .pieces for this file is created. Restart muwire still not in downloads.json and in the GUI. Search again for this file, add it for download now its visible in the gui and in downloads.json.

PS: No logging was enabled. Now I try with logging...

JamesOlvertone commented 2 years ago

Log is full with something like this:

2022-03-12 12:49:24.004 WARNING java_util_logging_Logger$log$7 call Exception while downloading java.lang.InterruptedException at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1048) at java.base/java.util.concurrent.Semaphore.acquire(Semaphore.java:318) at java_util_concurrent_Semaphore$acquire.call(Unknown Source) at com.muwire.core.connection.I2PConnector.connect(I2PConnector.groovy:75) at com.muwire.core.connection.I2PConnector$connect$0.call(Unknown Source) at com.muwire.core.download.NetworkDownloader$DownloadWorker.run(NetworkDownloader.groovy:360) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833)

I suspect adding files is done with a thread and here we have racecondition /deadlock ... If you add a lot of files at once you can see in the search results for each file a icon with a down arrow is added in realtime. But some of them were never added and stuck forever. The thing is even after a restart this files cannot be added after a new search, where only some files have not the "arrow down" status, adding some files shouldnt be a problem but here it is. Something locks here forever. I tested it on fresh install to get shure there isn't something else like a damaged status saved for this files. After searchung and trying adding again some of them (others not the same as before) hang again (too much files added at once -> maybe racecondtion/dead lock again) but after some retries it works and all files are in the download list.

zlatinb commented 2 years ago

This is a bit strange. The very first thing that happens after staring a download, before the .pieces file is created and before showing it in the GUI is that it gets written to downloads.json. So what you say

adding a new file, it does not appear in donwload.json, but appears in incompletes as .pieces

means the problem appears in the very beginning. If the download is not in downloads.json it will not be there when MuWire restarts.

Regarding the InterruptedException - MuWire has a limit of 4 connection attempts in progress to the same host. If you try to make more than 4 connections to the same host at the same time, they will wait until the earlier attempts finish. I don't think this is related, it just shows you did many downloads from the same host.

I'll try to reproduce this locally; if you can please keep testing to see if there is anything else in the logs besides the InterruptedException.

zlatinb commented 2 years ago

Hi again, I think I fixed one possible case where downloads.json can get corrupted in the commit referenced above. Can you please try the latest from git and see if the problem still appears?

JamesOlvertone commented 2 years ago

The following happened from the unpatched version (0.8.12-beta5):

There seems to be some situations where the download.json is corrupted for short time:

Logentry:

2022-03-12 13:13:11.231 FATAL java_util_logging_Logger$log$6 call exception dispatching event groovy.json.JsonException: expecting current character to be '"' with an int value of 34

The current character read is '"' with an int value of 34 expecting current character to be '"' with an int value of 34

line number 1 index number 372 {"file":"AKYv....","toShare":"AE...","length":1234,"pie

This line is an incomplete entry in downlods.json, but it only appears for a short time. After it appears in the log and checking downloads.json this line is not there anymore. Maybe its fixed automatically. When this error appeared I copied some files to the share folder. Maybe the autowatching mechanism tries to hash but the new file is not fully copied and again the file changed in size -> rehashing ist done... maybe this is the reason.... I dont know.

But now we know at least there are some situations where downloads.json gets corrupted.

PS: the "FATAL" is a translation I did, my log output is in local language. Maybe its in english SERVERE, FATAL whatever. I changed logout after this to english with -Duser.language=en.

I observed another strange behaviour. Above in another posting I I wrote that sometime files cannot be added and appear onyl after restart and readding manually. Now I observed this: Download a lot of files, watch in the search window how the "down arrow" ist added to more and more files you chosen for downloading. But there are some files that dont get this arrow like I told before. But some of them ARE downloaded and even finished when you look in your incomplete/donwloaded-folder The GUI seems to have a problem too bec. its not updated correctly. Maybe a Listenerproblem?

JamesOlvertone commented 2 years ago

How do I build the latest source?

I did a git pull origin master Checked what changed with gitk : Last entry is from today 14:19:51: 50333d10 ("lock persisting of downloader, trying to fix GitHub issue #124", 2022-03-12)

After building with /gradlew clean assemble I get version 0.8.11 files: ./gui/build/distributions: gui-shadow-0.8.11.tar gui-shadow-0.8.11.zip MuWire-0.8.11.tar MuWire-0.8.11.zip

zlatinb commented 2 years ago

The version that is built from ./gradlew clean assemble will have 0.8.11 in the file name but when you launch it it will show 0.8.12-beta5. So you have the latest code.

Regarding the down arrow in the GUI, that may be an unrelated issue. The GUI updates independently of the downloads, may be a timing issue. Let's take care of the download.json corruption first and then maybe open a separate issue for the down arrow.

JamesOlvertone commented 2 years ago

Seems to work now. The only files that exist as pieces and do not appear in the downloadlist are files that are duplicates that still exist in the share folder and that is expected behaviour.

Thank you for fixing.

zlatinb commented 2 years ago

Glad to hear it's working, but I'm not sure about the .pieces files. If you try to download a file that you already have it should just get copied without a .pieces file being created. I'll look into this further.

Closing the issue for now, thanks for testing!

JamesOlvertone commented 2 years ago

These .pieces were a sideffect of my testcycle, ignore this.