Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ChangeNotify was unable to decrypt #3187

Closed
sweharris opened this issue May 11, 2019 · 5 comments
Closed

ChangeNotify was unable to decrypt #3187

sweharris opened this issue May 11, 2019 · 5 comments
Milestone

Comments

@sweharris
Copy link
Contributor

@sweharris sweharris commented May 11, 2019

As mentioned at https://forum.rclone.org/t/changenotify-was-unable-to-decrypt/9561

Version:

rclone v1.46
- os/arch: linux/amd64
- go version: go1.11.5

Config entry:

[backups]
type = crypt
remote = Amazon:Backups
filename_encryption = off
password = imnotsaying
password2 = 

"Amazon" is Amazon Cloud Drive (ACD)

Mounted:

rclone mount backups: /mnt

So far so good.

Now in another window I try to do a compare between my local files and the Amazon encrypted files. eg diff -r /BACKUPS /mnt

And I start to see errors from the mount process:

2019/04/14 10:25:40 NOTICE: Encrypted drive 'backups:': ChangeNotify was unable to decrypt "hass": not an encrypted file - no ".bin" suffix
2019/04/14 10:25:40 NOTICE: Encrypted drive 'backups:': ChangeNotify was unable to decrypt "plexserver": not an encrypted file - no ".bin" suffix
2019/04/14 10:25:40 NOTICE: Encrypted drive 'backups:': ChangeNotify was unable to decrypt "monitor": not an encrypted file - no ".bin" suffix

The names mentioned in the errors are directories, not files.

-vv logs show entries such as:

2019/04/15 12:51:56 DEBUG : &{alexa/20180121.root.0.gz_aa (r)}: Read: len=131072, offset=690864128
2019/04/15 12:51:56 DEBUG : &{alexa/20180121.root.0.gz_aa (r)}: >Read: read=131072, err=<nil>
2019/04/15 12:51:56 DEBUG : &{alexa/20180121.root.0.gz_aa (r)}: Read: len=131072, offset=690995200
2019/04/15 12:51:56 NOTICE: Encrypted drive 'backups:': ChangeNotify was unable to decrypt "hass": not an encrypted file - no ".bin" suffix
2019/04/15 12:51:56 NOTICE: Encrypted drive 'backups:': ChangeNotify was unable to decrypt "plexserver": not an encrypted file - no ".bin" suffix
....
2019/04/15 12:51:56 DEBUG : &{alexa/20180121.root.0.gz_aa (r)}: >Read: read=131072, err=<nil>
2019/04/15 12:51:56 DEBUG : &{alexa/20180121.root.0.gz_aa (r)}: Read: len=131072, offset=691126272
2019/04/15 12:51:56 DEBUG : &{alexa/20180121.root.0.gz_aa (r)}: >Read: read=131072, err=<nil>

I definitely do have a directory called “hass” (“Home Assistant”) but the diff -r didn’t get to that directory until 1.5 hours later…

2019/04/15 14:16:51 DEBUG : /: Lookup: name="hass"
2019/04/15 14:16:51 DEBUG : /: >Lookup: node=hass/, err=<nil>
2019/04/15 14:16:51 DEBUG : hass/: Attr: 
2019/04/15 14:16:51 DEBUG : hass/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2019/04/15 14:16:51 DEBUG : hass/: ReadDirAll: 
2019/04/15 14:16:51 DEBUG : hass/: >ReadDirAll: item=78, err=<nil>
2019/04/15 14:16:51 DEBUG : hass/: Lookup: name="20190321._boot.0.gz_aa"

The code seems to be working; it’s just these odd NOTICE messages!

@ncw ncw added the bug label May 12, 2019
@ncw ncw added this to the v1.48 milestone May 12, 2019
@ncw ncw added the Remote: Crypt label May 12, 2019
@ncw

This comment has been minimized.

Copy link
Member

@ncw ncw commented May 12, 2019

Here is what I wrote in the forum:

Looking at the code this seems to be the problem

In the crypt backend

			wrappedNotifyFunc := func(path string, entryType fs.EntryType) {
				decrypted, err := f.DecryptFileName(path)
				if err != nil {
					fs.Logf(f, "ChangeNotify was unable to decrypt %q: %s", path, err)
					return
				}
				notifyFunc(decrypted, entryType)
			}
			doChangeNotify(wrappedNotifyFunc, pollInterval)

chhangenotify is ignoring the entrytype which will make a difference for filename_encryption = off. It should be calling DecryptDirName for directories.

Looking at the code now it looks correct - looks like I fixed that in cdf12b1 and didn't tell anyone!

So can you try the latest beta and see if that fixes it for you?

@sweharris

This comment has been minimized.

Copy link
Contributor Author

@sweharris sweharris commented May 12, 2019

With from version from the "latest" zip file

rclone v1.47.0-049-g7d70e926-beta
- os/arch: linux/386
- go version: go1.12.5

Hmm, that seems to be spewing out a tonne of different notices

eg

2019/05/12 08:09:52 NOTICE: Encrypted drive 'backups:': path "hass/20190411.log.bin" entryType 3
2019/05/12 08:09:52 NOTICE: Encrypted drive 'backups:': path "hass" entryType 2
2019/05/12 08:09:52 NOTICE: Encrypted drive 'backups:': path "mercury7/20190411._boot.4.gz_aa.bin" entryType 3
2019/05/12 08:09:52 NOTICE: Encrypted drive 'backups:': path "mercury7" entryType 2
2019/05/12 08:09:52 NOTICE: Encrypted drive 'backups:': path "penfold/20190411._FastData.4.gz_aa.bin" entryType 3
2019/05/12 08:09:52 NOTICE: Encrypted drive 'backups:': path "penfold" entryType 2

They almost look like debug messages, but I didn't have debugging turned on.

I'll redo the test with screenlog enabled and then filter the results to skip entryType lines.

@ncw

This comment has been minimized.

Copy link
Member

@ncw ncw commented May 12, 2019

They almost look like debug messages, but I didn't have debugging turned on.

They are stray debug messages - sorry! I've fixed that in the beta here:

https://beta.rclone.org/v1.47.0-062-g99bc013c-beta/ (uploaded in 15-30 mins)

@sweharris

This comment has been minimized.

Copy link
Contributor Author

@sweharris sweharris commented May 12, 2019

I didn't use the 062 beta, but left the older 049 version running. If I strip out those debug messages then everything worked fine until Amazon started "429 Too Many Requests" on me. But that was over 8 hours later.

So I think my initial problem has been fixed.

@ncw

This comment has been minimized.

Copy link
Member

@ncw ncw commented May 13, 2019

Excellent! Thanks for testing. I'll close this now :-)

@ncw ncw closed this May 13, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.