search

cryptomator / dokany-nio-adapter

Dokany-based adapter to provide directory contents specified by a java.nio.file.Path (via dokan-java)
GNU Affero General Public License v3.0
14 stars 4 forks source link

Google Drive File Stream: Certain applications do not write to file #39

Open infeo opened 4 years ago

infeo commented 4 years ago

Dokany-Nio-Adapter: 1.1.14 Dokan: 1.3.1.1000 Underlying filesystem: Google Drive File Stream OS: Windows 10 Pro 1909

Certain applications are not able to save altered documents when a location of a Google Drive File Stream volume is used.

An example is LibreOffice.

Steps to reproduce:

  1. Mirror with the adapter a Google Drive File Stream directory
  2. Create a Libre Office document (e.g. with Writer) on the location via the dokan mirror
  3. Alter the document and save the modification
  4. Close the application
  5. Reopen the document

Expected Behaviour

The altered content is shown

Actual Behaviour

The "old" content is shown

infeo commented 4 years ago

Log file:

23:23:57.080 [Thread-1347] TRACE o.c.frontend.dokany.ReadWriteAdapter - zwCreateFile() is called for /test.odt with the following parameters:
    CreateDisposition -- OPEN_EXISTING
    createOptions -- EnumIntegerSet(elements=[FILE_SYNCHRONOUS_IO_NONALERT, FILE_NON_DIRECTORY_FILE])
    accessMasks -- EnumIntegerSet(elements=[SYNCHRONIZE, READ_CONTROL, DELETE])
    fileAccessMasks -- EnumIntegerSet(elements=[])
    fileAttributes -- EnumIntegerSet(elements=[]).
23:23:57.081 [Thread-1347] TRACE o.c.frontend.dokany.ReadWriteAdapter - Try to open /test.odt as File.
23:23:57.087 [Thread-1347] TRACE o.c.cryptofs.fh.FileHeaderHolder - Reading file header from L:\My Drive\asd\d\J3\2XOHSDWOV4I7THLLDLNX6LKLXYT47Q\eQZCwp6v1NcpD8TcTRmW8QYswNFEZmqp.c9r
23:23:57.087 [Thread-1347] TRACE o.c.cryptofs.fh.OpenCryptoFile - First channel for this openFile. Initializing file size...
23:23:57.087 [Thread-1347] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) /test.odt opened successful with handle 201.
23:23:57.088 [Thread-1349] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt.
23:23:57.088 [Thread-1349] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt is 9025.
23:23:57.088 [Thread-1349] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt.
23:23:57.089 [Thread-1351] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt.
23:23:57.090 [Thread-1351] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt is 9025.
23:23:57.090 [Thread-1351] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt.
23:23:57.090 [Thread-1353] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt.
23:23:57.090 [Thread-1353] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt is 9025.
23:23:57.090 [Thread-1353] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt.
23:23:57.091 [Thread-1355] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt.
23:23:57.091 [Thread-1355] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt is 9025.
23:23:57.091 [Thread-1355] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt.
23:23:57.091 [Thread-1357] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt.
23:23:57.092 [Thread-1357] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt is 9025.
23:23:57.092 [Thread-1357] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt.
23:23:57.092 [Thread-1358] TRACE o.c.frontend.dokany.ReadWriteAdapter - zwCreateFile() is called for /lu12284cvp7.tmp with the following parameters:
    CreateDisposition -- OPEN_EXISTING
    createOptions -- EnumIntegerSet(elements=[FILE_SYNCHRONOUS_IO_NONALERT, FILE_NON_DIRECTORY_FILE])
    accessMasks -- EnumIntegerSet(elements=[GENERIC_READ, GENERIC_WRITE, WRITE_OWNER, WRITE_DAC, DELETE])
    fileAccessMasks -- EnumIntegerSet(elements=[])
    fileAttributes -- EnumIntegerSet(elements=[]).
23:23:57.093 [Thread-1358] TRACE o.c.frontend.dokany.ReadWriteAdapter - Try to open /lu12284cvp7.tmp as File.
23:23:57.099 [Thread-1358] TRACE o.c.cryptofs.fh.FileHeaderHolder - Reading file header from L:\My Drive\asd\d\J3\2XOHSDWOV4I7THLLDLNX6LKLXYT47Q\ZjJ4gKcDDWrvx5Y_j1OmTrG1Ftd2rUwa3aE_NzfCYg==.c9r
23:23:57.099 [Thread-1358] TRACE o.c.cryptofs.fh.OpenCryptoFile - First channel for this openFile. Initializing file size...
23:23:57.099 [Thread-1358] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) /lu12284cvp7.tmp opened successful with handle 202.
23:23:57.099 [Thread-1360] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.100 [Thread-1360] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.100 [Thread-1360] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.100 [Thread-1362] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.101 [Thread-1362] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.101 [Thread-1362] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.101 [Thread-1364] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.102 [Thread-1364] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.102 [Thread-1364] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.102 [Thread-1366] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.102 [Thread-1366] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.102 [Thread-1366] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.103 [Thread-1368] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.103 [Thread-1368] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.103 [Thread-1368] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.104 [Thread-1370] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.104 [Thread-1370] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.104 [Thread-1370] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.105 [Thread-1373] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.105 [Thread-1373] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.105 [Thread-1373] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.105 [Thread-1375] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) readFile() is called for /lu12284cvp7.tmp.
23:23:57.106 [Thread-1375] TRACE o.c.frontend.dokany.OpenFile - Reading 0-4096 (0-12288)
23:23:57.106 [Thread-1375] TRACE o.c.frontend.dokany.OpenFile - Reading 4096-8192 (0-12288)
23:23:57.106 [Thread-1375] TRACE o.c.frontend.dokany.OpenFile - Reading 8192-9057 (0-12288)
23:23:57.106 [Thread-1375] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Data successful read from /lu12284cvp7.tmp.
23:23:57.110 [Thread-1377] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.111 [Thread-1377] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.111 [Thread-1377] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.111 [Thread-1379] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt.
23:23:57.112 [Thread-1379] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt is 9025.
23:23:57.112 [Thread-1379] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt.
23:23:57.112 [Thread-1381] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.113 [Thread-1381] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.113 [Thread-1381] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.113 [Thread-1382] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) setFileAttributes() is called for /lu12284cvp7.tmp.
23:23:57.116 [Thread-1384] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) setFileTime() is called for /lu12284cvp7.tmp.
23:23:57.117 [Thread-1384] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Successful updated Filetime for /lu12284cvp7.tmp.
23:23:57.117 [Thread-1386] TRACE o.c.frontend.dokany.ReadWriteAdapter - zwCreateFile() is called for /test.odt~RF6fbc9d.TMP with the following parameters:
    CreateDisposition -- CREATE_NEW
    createOptions -- EnumIntegerSet(elements=[FILE_SYNCHRONOUS_IO_NONALERT, FILE_NON_DIRECTORY_FILE])
    accessMasks -- EnumIntegerSet(elements=[GENERIC_WRITE, DELETE])
    fileAccessMasks -- EnumIntegerSet(elements=[HIDDEN, TEMPORARY])
    fileAttributes -- EnumIntegerSet(elements=[HIDDEN, TEMPORARY]).
23:23:57.118 [Thread-1386] TRACE o.c.frontend.dokany.ReadWriteAdapter - Try to open /test.odt~RF6fbc9d.TMP as File.
23:23:57.118 [Thread-1386] TRACE o.c.frontend.dokany.ReadWriteAdapter - Could not read file attributes.
23:23:57.121 [Thread-1386] TRACE o.c.cryptofs.fh.FileHeaderHolder - Generating file header for L:\My Drive\asd\d\J3\2XOHSDWOV4I7THLLDLNX6LKLXYT47Q\VgAuWgQcSMHf2eDN4Jno5KpZmt5QUwv4PMMr3K4CwTNqf6MV9A==.c9r
23:23:57.121 [Thread-1386] TRACE o.c.cryptofs.fh.OpenCryptoFile - First channel for this openFile. Initializing file size...
23:23:57.122 [Thread-1386] DEBUG o.c.frontend.dokany.FileUtil - Windows file attribute TEMPORARY is currently not supported and thus will be ignored
23:23:57.124 [Thread-1386] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) /test.odt~RF6fbc9d.TMP opened successful with handle 203.
23:23:57.124 [Thread-1388] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.125 [Thread-1388] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.125 [Thread-1388] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.125 [Thread-1390] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.125 [Thread-1390] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.125 [Thread-1390] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.126 [Thread-1392] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.126 [Thread-1392] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.126 [Thread-1392] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.126 [Thread-1394] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.127 [Thread-1394] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.127 [Thread-1394] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.127 [Thread-1396] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.128 [Thread-1396] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.128 [Thread-1396] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.128 [Thread-1397] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) cleanup() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.128 [Thread-1397] TRACE o.c.cryptofs.ch.CleartextFileChannel - org.cryptomator.cryptofs.ch.CleartextFileChannel@1badd2c1 - Writing file header.
23:23:57.130 [Thread-1398] TRACE o.c.frontend.dokany.ReadWriteAdapter - (203) closeFile() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.130 [Thread-1400] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt.
23:23:57.132 [Thread-1400] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt is 9025.
23:23:57.132 [Thread-1400] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt.
23:23:57.132 [Thread-1401] TRACE o.c.frontend.dokany.ReadWriteAdapter - zwCreateFile() is called for /test.odt~RF6fbc9d.TMP with the following parameters:
    CreateDisposition -- OPEN_EXISTING
    createOptions -- EnumIntegerSet(elements=[])
    accessMasks -- EnumIntegerSet(elements=[SYNCHRONIZE])
    fileAccessMasks -- EnumIntegerSet(elements=[])
    fileAttributes -- EnumIntegerSet(elements=[]).
23:23:57.133 [Thread-1401] TRACE o.c.frontend.dokany.ReadWriteAdapter - Try to open /test.odt~RF6fbc9d.TMP as File.
23:23:57.136 [Thread-1401] TRACE o.c.cryptofs.fh.FileHeaderHolder - Reading file header from L:\My Drive\asd\d\J3\2XOHSDWOV4I7THLLDLNX6LKLXYT47Q\VgAuWgQcSMHf2eDN4Jno5KpZmt5QUwv4PMMr3K4CwTNqf6MV9A==.c9r
23:23:57.136 [Thread-1401] TRACE o.c.cryptofs.fh.OpenCryptoFile - First channel for this openFile. Initializing file size...
23:23:57.136 [Thread-1401] TRACE o.c.frontend.dokany.ReadWriteAdapter - (204) /test.odt~RF6fbc9d.TMP opened successful with handle 204.
23:23:57.136 [Thread-1402] TRACE o.c.frontend.dokany.ReadWriteAdapter - (204) cleanup() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.138 [Thread-1403] TRACE o.c.frontend.dokany.ReadWriteAdapter - (204) closeFile() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.140 [Thread-1405] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) moveFile() is called for /test.odt.
23:23:57.141 [Thread-1405] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Successful moved resource /test.odt to /test.odt~RF6fbc9d.TMP.
23:23:57.142 [Thread-1407] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.142 [Thread-1407] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt~RF6fbc9d.TMP is 9025.
23:23:57.142 [Thread-1407] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.143 [Thread-1409] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.143 [Thread-1409] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) Filesize of /test.odt~RF6fbc9d.TMP is 9025.
23:23:57.143 [Thread-1409] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.144 [Thread-1413] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /lu12284cvp7.tmp.
23:23:57.144 [Thread-1413] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /lu12284cvp7.tmp is 9057.
23:23:57.144 [Thread-1413] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /lu12284cvp7.tmp.
23:23:57.144 [Thread-1414] TRACE o.c.frontend.dokany.ReadWriteAdapter - zwCreateFile() is called for /test.odt with the following parameters:
    CreateDisposition -- OPEN_EXISTING
    createOptions -- EnumIntegerSet(elements=[])
    accessMasks -- EnumIntegerSet(elements=[SYNCHRONIZE])
    fileAccessMasks -- EnumIntegerSet(elements=[])
    fileAttributes -- EnumIntegerSet(elements=[]).
23:23:57.145 [Thread-1414] TRACE o.c.frontend.dokany.ReadWriteAdapter - Try to open /test.odt as File.
23:23:57.146 [Thread-1414] TRACE o.c.cryptofs.fh.FileHeaderHolder - Reading file header from L:\My Drive\asd\d\J3\2XOHSDWOV4I7THLLDLNX6LKLXYT47Q\eQZCwp6v1NcpD8TcTRmW8QYswNFEZmqp.c9r
23:23:57.146 [Thread-1414] TRACE o.c.cryptofs.fh.OpenCryptoFile - First channel for this openFile. Initializing file size...
23:23:57.147 [Thread-1414] TRACE o.c.frontend.dokany.ReadWriteAdapter - (206) /test.odt opened successful with handle 206.
23:23:57.147 [Thread-1415] TRACE o.c.frontend.dokany.ReadWriteAdapter - (206) cleanup() is called for /test.odt.
23:23:57.148 [Thread-1416] TRACE o.c.frontend.dokany.ReadWriteAdapter - (206) closeFile() is called for /test.odt.
23:23:57.149 [Thread-1418] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) moveFile() is called for /lu12284cvp7.tmp.
23:23:57.150 [Thread-1418] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Successful moved resource /lu12284cvp7.tmp to /test.odt.
23:23:57.150 [Thread-1420] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /test.odt.
23:23:57.151 [Thread-1420] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /test.odt is 9057.
23:23:57.151 [Thread-1420] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /test.odt.
23:23:57.151 [Thread-1422] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) getFileInformation() is called for /test.odt.
23:23:57.152 [Thread-1422] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) Filesize of /test.odt is 9057.
23:23:57.152 [Thread-1422] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) File Information successful read from /test.odt.
23:23:57.152 [Thread-1425] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) cleanup() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.153 [Thread-1426] TRACE o.c.frontend.dokany.ReadWriteAdapter - (201) closeFile() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.153 [Thread-1427] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) cleanup() is called for /test.odt.
23:23:57.155 [Thread-1428] TRACE o.c.frontend.dokany.ReadWriteAdapter - (202) closeFile() is called for /test.odt.
23:23:57.155 [Thread-1429] TRACE o.c.frontend.dokany.ReadWriteAdapter - zwCreateFile() is called for /test.odt~RF6fbc9d.TMP with the following parameters:
    CreateDisposition -- OPEN_EXISTING
    createOptions -- EnumIntegerSet(elements=[FILE_NON_DIRECTORY_FILE])
    accessMasks -- EnumIntegerSet(elements=[DELETE])
    fileAccessMasks -- EnumIntegerSet(elements=[])
    fileAttributes -- EnumIntegerSet(elements=[]).
23:23:57.156 [Thread-1429] TRACE o.c.frontend.dokany.ReadWriteAdapter - Try to open /test.odt~RF6fbc9d.TMP as File.
23:23:57.158 [Thread-1429] TRACE o.c.cryptofs.fh.FileHeaderHolder - Reading file header from L:\My Drive\asd\d\J3\2XOHSDWOV4I7THLLDLNX6LKLXYT47Q\VgAuWgQcSMHf2eDN4Jno5KpZmt5QUwv4PMMr3K4CwTNqf6MV9A==.c9r
23:23:57.158 [Thread-1429] TRACE o.c.cryptofs.fh.OpenCryptoFile - First channel for this openFile. Initializing file size...
23:23:57.159 [Thread-1429] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) /test.odt~RF6fbc9d.TMP opened successful with handle 208.
23:23:57.159 [Thread-1431] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.159 [Thread-1431] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.160 [Thread-1431] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.160 [Thread-1433] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.160 [Thread-1433] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.160 [Thread-1433] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.161 [Thread-1435] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.161 [Thread-1435] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.161 [Thread-1435] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.161 [Thread-1437] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.162 [Thread-1437] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.162 [Thread-1437] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.162 [Thread-1439] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.163 [Thread-1439] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.163 [Thread-1439] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.163 [Thread-1441] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.163 [Thread-1441] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.163 [Thread-1441] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.164 [Thread-1443] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) getFileInformation() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.164 [Thread-1443] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) Filesize of /test.odt~RF6fbc9d.TMP is 0.
23:23:57.164 [Thread-1443] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) File Information successful read from /test.odt~RF6fbc9d.TMP.
23:23:57.164 [Thread-1444] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) deleteFile() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.165 [Thread-1444] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) Deletion of /test.odt~RF6fbc9d.TMP possible.
23:23:57.165 [Thread-1445] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) cleanup() is called for /test.odt~RF6fbc9d.TMP.
23:23:57.171 [Thread-1445] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) /test.odt~RF6fbc9d.TMP successful deleted.
23:23:57.171 [Thread-1446] TRACE o.c.frontend.dokany.ReadWriteAdapter - (208) closeFile() is called for /test.odt~RF6fbc9d.TMP.
infeo commented 4 years ago

The intersting part is approximately in the middle:

  1. LibreOffice creates the file /test.odt~RF6fbc9d.TMP
  2. Afterwards it moves /test.odt to /test.odt~RF6fbc9d.TMP successfully
  3. Right after a handle to /test.odt is opened -> this should not happen
infeo commented 4 years ago

LibreOffices does the following to save a document:

  1. Create a temporary file and save every change there (lu71443c6tl.tmp)
  2. move the original file to another temporary file (test.odt~RF55da07.TMP)
  3. move the file with the changes to the original file name

A more condensed log:

11:17:52:713 [Thread-409] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) readFile() is called for L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:713 [Thread-409] TRACE org.cryptomator.frontend.dokany.OpenFile - Reading 0-4096 (0-12288)
11:17:52:713 [Thread-409] TRACE org.cryptomator.frontend.dokany.OpenFile - Reading 4096-8192 (0-12288)
11:17:52:713 [Thread-409] TRACE org.cryptomator.frontend.dokany.OpenFile - Reading 8192-8934 (0-12288)
11:17:52:713 [Thread-409] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) Data successful read from L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:713 [Thread-410] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) getFileInformation() is called for L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:713 [Thread-410] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) Filesize of L:\My Drive\qwe\lu71443c6tl.tmp is 8934.
11:17:52:713 [Thread-410] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) File Information successful read from L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:713 [Thread-411] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) getFileInformation() is called for L:\My Drive\qwe\test.odt.
11:17:52:713 [Thread-411] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) Filesize of L:\My Drive\qwe\test.odt is 0.
11:17:52:713 [Thread-411] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) File Information successful read from L:\My Drive\qwe\test.odt.
11:17:52:713 [Thread-412] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) getFileInformation() is called for L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:713 [Thread-412] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) Filesize of L:\My Drive\qwe\lu71443c6tl.tmp is 8934.
11:17:52:713 [Thread-412] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) File Information successful read from L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:713 [Thread-413] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) setFileAttributes() is called for L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:713 [Thread-414] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) setFileTime() is called for L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:713 [Thread-414] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) Successful updated Filetime for L:\My Drive\qwe\lu71443c6tl.tmp.
/**
 skipped
 **/
11:17:52:735 [Thread-432] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) moveFile() is called for L:\My Drive\qwe\test.odt.
11:17:52:735 [Thread-432] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) Successful moved resource L:\My Drive\qwe\test.odt to L:\My Drive\qwe\test.odt~RF55da07.TMP.
11:17:52:735 [Thread-433] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) getFileInformation() is called for L:\My Drive\qwe\test.odt~RF55da07.TMP.
11:17:52:735 [Thread-433] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) Filesize of L:\My Drive\qwe\test.odt~RF55da07.TMP is 0.
11:17:52:735 [Thread-433] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) File Information successful read from L:\My Drive\qwe\test.odt~RF55da07.TMP.
11:17:52:735 [Thread-434] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) getFileInformation() is called for L:\My Drive\qwe\test.odt~RF55da07.TMP.
11:17:52:735 [Thread-434] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) Filesize of L:\My Drive\qwe\test.odt~RF55da07.TMP is 0.
11:17:52:735 [Thread-434] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (65) File Information successful read from L:\My Drive\qwe\test.odt~RF55da07.TMP.
11:17:52:735 [Thread-436] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (69) cleanup() is called for L:\My Drive\qwe.
11:17:52:735 [Thread-437] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (69) closeFile() is called for L:\My Drive\qwe.
11:17:52:735 [Thread-438] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) getFileInformation() is called for L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:735 [Thread-438] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) Filesize of L:\My Drive\qwe\lu71443c6tl.tmp is 8934.
11:17:52:735 [Thread-438] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) File Information successful read from L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:735 [Thread-439] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - zwCreateFile() is called for L:\My Drive\qwe\test.odt with the following parameters:
    CreateDisposition -- OPEN_EXISTING
    createOptions -- EnumIntegerSet(elements=[])
    accessMasks -- EnumIntegerSet(elements=[SYNCHRONIZE])
    fileAccessMasks -- EnumIntegerSet(elements=[])
    fileAttributes -- EnumIntegerSet(elements=[]).
11:17:52:735 [Thread-439] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - Try to open L:\My Drive\qwe\test.odt as File.
11:17:52:735 [Thread-439] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (70) L:\My Drive\qwe\test.odt opened successful with handle 70.
11:17:52:735 [Thread-441] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (70) cleanup() is called for L:\My Drive\qwe\test.odt.
11:17:52:735 [Thread-442] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (70) closeFile() is called for L:\My Drive\qwe\test.odt.
11:17:52:735 [Thread-445] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) moveFile() is called for L:\My Drive\qwe\lu71443c6tl.tmp.
11:17:52:735 [Thread-445] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) Successful moved resource L:\My Drive\qwe\lu71443c6tl.tmp to L:\My Drive\qwe\test.odt.
11:17:52:735 [Thread-446] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) getFileInformation() is called for L:\My Drive\qwe\test.odt.
11:17:52:735 [Thread-446] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) Filesize of L:\My Drive\qwe\test.odt is 0.
11:17:52:735 [Thread-446] TRACE org.cryptomator.frontend.dokany.ReadWriteAdapter - (66) File Information successful read from L:\My Drive\qwe\test.odt.
infeo commented 4 years ago

The problem is, that an already moved resource (test.odt to test.odt~RF55da07.TMP) is still present afterwards and instead of throwing a NoSuchFileException an access is successful. (see the zwCreateFile() call)

infeo commented 4 years ago

The problem is an upstream-bug in the JDK: When moving a file with the REPLACE_EXISTING flag via the File.move() method in a GDFS, it silently fails (i.e. no throw of an exception).

I have submitted a ticket on the JDK bug tracker (JDK-8245185)). Until its resolution, the workaround is to delete the target of the move operation beforehand.

infeo commented 4 years ago

Okay, bug got closed with the label "not reproducable". We may test it more to be completely sure about this and maybe recreate the bug report. @cryptomator/libraries can somebody test this on anopther setup?