cryptomator / cryptofs

Java Filesystem Provider with integrated encryption
GNU Affero General Public License v3.0
94 stars 35 forks source link

Race Condition during read #85

Closed ldexterldesign closed 4 years ago

ldexterldesign commented 4 years ago

Hi all,

Thanks for saving my privacy!

Hope you're well

As title

I'm trying to transfer the contents of my vault to a new vault (didn't work so now trying something simpler) my desktop (same issue) but getting the following error when transferring (e.g. moving / copy/pasting):

The operation can’t be completed because an unexpected error occurred (error code -8084).

Surprisingly not much info' to troubleshoot this error online

I've inspected the files for permissions and/or extended attributes but nothing sticks out. The only pattern I see is that it appears to be larger single files (e.g. >100mb, mainly video) and these flat out won't transfer in macOS so I have to resort to using shell (i.e. cp command).

I'm left having to prune transfer files every time the bulk transfer aborts which is very time consuming

Log


20:10:10.677 [webdav-021] TRACE o.c.cryptofs.fh.FileHeaderHolder - Reading file header from /Users/ldexterldesign/Dropbox/-cryptomator/d/HF/I6MBKU6J6G6UWKBJTE3GOAOZ63IHEF/wJllgWKdNlM_3sKaVnVGC-Qdk5fOcaWz4CjtdznqxcoiTyUwLEvyWDtMFuMCZr6BzjMrzG0H0w==.c9r
20:10:10.732 [webdav-037] WARN  org.eclipse.jetty.server.HttpChannel - /qvgmvaH5TvbR/_cryptomator/gtd/home/calendar/Organise%20account%20-%20twitter/Process%20tweet/twitter-2019-12-07-59e7288a255725700004be85f4ee16f45047f963061f124dee8c90fb4b63eeeb/tweet_media/875777885935726592-5RMr_2E1orBy5-Fb.mp4
java.lang.IllegalArgumentException: newPosition < 0: (32768 < 0)
    at java.base/java.nio.Buffer.createPositionException(Unknown Source)
    at java.base/java.nio.Buffer.position(Unknown Source)
    at java.base/java.nio.ByteBuffer.position(Unknown Source)
    at java.base/java.nio.HeapByteBuffer.put(Unknown Source)
    at org.cryptomator.cryptofs.fh.ChunkData$1.to(ChunkData.java:58)
    at org.cryptomator.cryptofs.ch.CleartextFileChannel.readLocked(CleartextFileChannel.java:110)
    at org.cryptomator.cryptofs.ch.AbstractFileChannel.read(AbstractFileChannel.java:155)
    at org.cryptomator.cryptofs.ch.AbstractFileChannel.read(AbstractFileChannel.java:139)
    at java.base/sun.nio.ch.ChannelInputStream.read(Unknown Source)
    at java.base/sun.nio.ch.ChannelInputStream.read(Unknown Source)
    at java.base/sun.nio.ch.ChannelInputStream.read(Unknown Source)
    at java.base/java.io.InputStream.transferTo(Unknown Source)
    at java.base/java.nio.file.Files.copy(Unknown Source)
    at org.cryptomator.webdav.core.servlet.DavFile.spool(DavFile.java:64)
    at org.apache.jackrabbit.webdav.server.AbstractWebdavServlet.spoolResource(AbstractWebdavServlet.java:553)
    at org.apache.jackrabbit.webdav.server.AbstractWebdavServlet.doGet(AbstractWebdavServlet.java:519)
    at org.cryptomator.webdav.core.servlet.AbstractNioWebDavServlet.doGet(AbstractNioWebDavServlet.java:111)
    at org.apache.jackrabbit.webdav.server.AbstractWebdavServlet.execute(AbstractWebdavServlet.java:360)
    at org.cryptomator.webdav.core.servlet.AbstractNioWebDavServlet.execute(AbstractNioWebDavServlet.java:95)
    at org.apache.jackrabbit.webdav.server.AbstractWebdavServlet.service(AbstractWebdavServlet.java:308)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1631)
    at org.cryptomator.webdav.core.filters.MacChunkedPutCompatibilityFilter.doFilterHttp(MacChunkedPutCompatibilityFilter.java:51)
    at org.cryptomator.webdav.core.filters.HttpFilter.doFilter(HttpFilter.java:21)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
    at org.cryptomator.webdav.core.filters.AcceptRangeFilter.doFilterHttp(AcceptRangeFilter.java:37)
    at org.cryptomator.webdav.core.filters.HttpFilter.doFilter(HttpFilter.java:21)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
    at org.cryptomator.webdav.core.filters.MkcolComplianceFilter.doFilterHttp(MkcolComplianceFilter.java:40)
    at org.cryptomator.webdav.core.filters.HttpFilter.doFilter(HttpFilter.java:21)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
    at org.cryptomator.webdav.core.filters.PostRequestBlockingFilter.doFilterHttp(PostRequestBlockingFilter.java:39)
    at org.cryptomator.webdav.core.filters.HttpFilter.doFilter(HttpFilter.java:21)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
    at org.cryptomator.webdav.core.filters.UnicodeResourcePathNormalizationFilter.doFilterHttp(UnicodeResourcePathNormalizationFilter.java:53)
    at org.cryptomator.webdav.core.filters.HttpFilter.doFilter(HttpFilter.java:21)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
    at org.cryptomator.webdav.core.filters.LoggingFilter.doFilterHttp(LoggingFilter.java:29)
    at org.cryptomator.webdav.core.filters.HttpFilter.doFilter(HttpFilter.java:21)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:549)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1363)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1278)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:221)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.Server.handle(Server.java:500)
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.base/java.lang.Thread.run(Unknown Source)

☝️ Again, notice here it's a .mp4 (i.e. video file)

Screen shot:

Screenshot 2020-06-03 at 19 45 11

Anyone have any clue what's going on here or any possible workaround?

If you're reading and:

Welcome feedback/input

If you have any issues (e.g. questions/queries) then happy to help

Keep up great work!

Hope this helps & to hear back

Sincerely

hardware: Apple, MacBook Pro (16-inch, 2019) software - operating system: Apple, macOS, 10.15.4 (19E287) software - application: cryptomator, 1.5.5 (dmg-2260.108)

ldexterldesign commented 4 years ago

👋 https://community.cryptomator.org/t/error-8084-frequently/1334

ldexterldesign commented 4 years ago

Strangely, ditto (basically macOS version of cp) says these .mp4 files don't exist, all other ~4000 files transferred successfully:

Screenshot 2020-06-03 at 20 32 03

... so I suspect cryptomator (and/or Dropbox, where the vault was stored) has mangled these files 😕

ldexterldesign commented 4 years ago

Huff, poor macOS Finder search performance, unsure if this is connected but I'd consider it normal?:

Screenshot 2020-06-03 at 20 54 17

FYI the original goal of transferring the contents of my vault to a new one was to see if performance would be better (inc. macOS enabling Spotlight, but I now presume this is a separate issue)

ldexterldesign commented 4 years ago

FYI the ~3 files which didn't transfer here transferred OK on their own (i.e. one by one)

ldexterldesign commented 4 years ago
ldexterldesign@Lewiss-MacBook-Pro ~ % ls -l /Volumes/_cryptomator/gtd/home/calendar/Sanitise\ device\ -\ apple/serif/affinity
total 3487972
-rwx------@ 1 ldexterldesign  staff  599132806 21 Feb 09:26 designer - 1.8.0.5 - tnt.dmg
-rwx------@ 1 ldexterldesign  staff        247 21 Feb 10:11 mac-torrents.io.webloc
-rwx------@ 1 ldexterldesign  staff  588954246 21 Feb 09:26 photo - 1.8.0.166 - tnt.dmg
-rwx------@ 1 ldexterldesign  staff  597752454 21 Feb 09:26 publisher - 1.8.0.556 - tnt.dmg

The designer* and photo* files here won't transfer by any means (inc. cp, ditto). I compressed (i.e. native macOS zip) them and transferred the Archive.zip successfully but get this error when attempting to uncompress Archive.zip:

Screenshot 2020-06-03 at 21 17 50

... so I think it's safe to say between cryptomator and/or Dropbox these files got corrupted which doesn't leave me feeling confident about using cryptomator and/or Dropbox again 😟

overheadhunter commented 4 years ago

Why the hell does it claim 32768 < 0?

I think what the buffer meant to say is: 32768 >= 32768. The position inside a chunk must be within [0; 32768[. @cryptomator/libraries we should check our arithmetic.

overheadhunter commented 4 years ago

Problem seems to lie in this piece of code that can be invoked simultaneously by multiple threads:

https://github.com/cryptomator/cryptofs/blob/473fecf949304722af87fe54d20725ee3b499935/src/main/java/org/cryptomator/cryptofs/fh/ChunkData.java#L55-L59

The problem with this is, that the limit/position of the same non-threadsafe instance gets modified. Instead every thread should use its own markers.

Side note: Same applies to writing in theory, however this error never occurred due to exclusive write locks in other places (fuse-nio-adapter, dokany-nio-adapter).

ldexterldesign commented 4 years ago

Hi @overheadhunter,

Thanks for reply

Do you know the cause of my issue and whether it will happen again?

Sincerely

overheadhunter commented 4 years ago

Do you know the cause of my issue

Yes, see previous comment. We think we fixed it and scheduled the fix for the next release.

whether it will happen again

With the current version, it might happen again, if multiple threads read from the same file simultaneously. This is completely recoverable and your data is unharmed, since this bug can not happen during write (due to exclusive locking).

That said, as a temporary workaround you can switch on single-threaded mode by adding -s to the FUSE mount options in your vault options dialog.