DobyTang / LazyLibrarian

This project isn't finished yet. Goal is to create a SickBeard, CouchPotato, Headphones-like application for ebooks. Headphones is used as a base, so there are still a lot of references to it.
732 stars 70 forks source link

Creating folders on Google Drive File Stream #1244

Closed kalo8450 closed 6 years ago

kalo8450 commented 6 years ago

LazyLibrarian version number Current Version: fe5ff30ab1d096f355e3aa2cd5b2005d49f1b175

Operating system used Windows 10

Interface in use Default

Which api both

Source of your LazyLibrarian installation git

Relevant debug log with api keys and any passwords redacted

I have recently tried to save my Magazines directly to Google File Stream but all my downloads fail with the same error message:

2018-02-27 22:36:58 ERROR Postprocessing for New Scientist(2018-02-24) has failed: Unable to create directory K:\My Drive\Magazines\New Scientist: Access is denied

If you try to create a folder which already exists on Google File Stream it prompts a Confirm Folder Replace dialog to ask how to deal with the clash. This is not what would be expected to happen under Windows and is I presume why all my downloads have started to fail.

Can I ask that the existence of a folder is checked before an attempt is made to create it. I suspect that it will also be necessary to check if a file of the same name already exists in the folder when attempting to save the file as a similar how do you want to deal with the clash situation will arise.

philborman commented 6 years ago

I don't think that's quite it, need more info please. We do check for the existence of a folder before creating. If you turn debug logging on you should get more info, messages saying things like Folder does not exist, so it's safe to create it File exists but is not a directory, deleting it

I don't have access to Google File Stream, so can't check myself. It's a fairly small section of code in the postprocessor that we need to focus on, and the debug log covers most of it quite well. I'm guessing one of the tests is failing or returning an unexpected answer (does file exist, is it a directory), or we fail to set permissions on the directory and get an unexpected answer back. You would need loglevel 3 or more to pick that message up though, as we treat it as non-fatal, but google might not.

kalo8450 commented 6 years ago

Thanks for the prompt reply. I set Log Level: to 3 in settings but regardless when I turned logging on it said level 2. Here is a sample from the log, all down loads are the same and the folders do exist.

2018-02-28 12:07:51 WARNING POSTPROCESS postprocess.py processDir 752 Residual files remain in D:\Downloads\sabnzbd\complete\books\PC Pro TruePDF-April 2018.fail
2018-02-28 12:07:51 ERROR POSTPROCESS postprocess.py processDir 731 Postprocessing for PC Pro(2018-04-01) has failed: Unable to create directory K:\My Drive\Magazines\PC Pro: Access is denied
2018-02-28 12:07:51 DEBUG POSTPROCESS postprocess.py processDestination 1236 K:\My Drive\Magazines\PC Pro does not exist, so it's safe to create it

I then tried to download a new magazine and got this:

2018-02-28 12:26:57 WARNING POSTPROCESS postprocess.py processDir 752 Residual files remain in D:\Downloads\sabnzbd\complete\books\Practical Photoshop TruePDF-January 2018.fail
2018-02-28 12:26:57 ERROR POSTPROCESS postprocess.py processDir 731 Postprocessing for Practical Photoshop(2018-01-01) has failed: Unable to create directory K:\My Drive\Magazines\Practical Photoshop: Access is denied
2018-02-28 12:26:57 DEBUG POSTPROCESS postprocess.py processDestination 1236 K:\My Drive\Magazines\Practical Photoshop does not exist, so it's safe to create it
2018-02-28 12:26:57 DEBUG POSTPROCESS postprocess.py processDestination 1234 BookType: mag, calibredb: []
2018-02-28 12:26:57 DEBUG POSTPROCESS postprocess.py processDir 588 Processing magazine Practical Photoshop

Checked and folder has not been created. The plot thickens

philborman commented 6 years ago

I see you have closed this, was that intended? The loglevel 3 change is probably because you changed the level but did not save config? Or if you start lazylibrarian from the command line with --debug you override the config setting.

Seems there is a difference between the way google drive file system works and the way the python libraries expect things to work. Could be fun trying to track it down, are you up for a bit of editing?

The section of code of interest is in postprocess.py line 1236 as shown in your log above. We seem to get the "file does not exist" part ok, then should try to create it with os.makedirs() This should create the folder we want and any intermediate folders needed to get there. ie if K:\My Drive\Magazines\Practical Photoshop is the eventual target but K:\My Drive\Magazines doesn't exist we have to create that first. Maybe that's the part that google doesn't like. We could alter this to check the intermediate ones ourselves, the "access denied" error could be because we're trying to make the intermediate folder without checking first? Or could be we are not logged in (do we need to be?)

kalo8450 commented 6 years ago

Your right I didn't mean to close. I've updated to include your commit. I've set debug level to 3, saved, restarted and rechecked debug level is 3 but still says level 2 when I turn on debugging and resets debug level to 2 in the config. All folders exist in the path except for the Practical photoshop one. We are logged in, Drive Stream creates a virtual hard drive which you access as though it were attached to the PC. Download still fails but new error.

2018-02-28 21:24:12 ERROR POSTPROCESS postprocess.py processDir 727 Postprocessing for practical photoshop(2018-03-01) has failed: Unable to create directory K:\My Drive\Magazines\practical photoshop: maximum recursion depth exceeded in cmp
2018-02-28 21:24:12 DEBUG POSTPROCESS postprocess.py processDestination 1232 K:\My Drive\Magazines\practical photoshop does not exist, so it's safe to create it
2018-02-28 21:24:12 DEBUG POSTPROCESS postprocess.py processDestination 1230 BookType: mag, calibredb: []
2018-02-28 21:24:12 DEBUG POSTPROCESS postprocess.py processDir 584 Processing magazine practical photoshop

Thanks again for the prompt attention and I am more than willing to help track the problem down

kalo8450 commented 6 years ago

Been ferreting through mymakedirs, could this be linked to issue #1074. "My Drive" in the path is fixed and cannot be renamed.

philborman commented 6 years ago

No, spaces in filenames don't matter at this point, the python filename splitting takes care of that. The interesting bit is by using our own routine we got an error message that makes a little more sense. mymakedirs() is a recursive routine (hence the maximum recursion depth error) and we are not exiting the loop properly.

The mymakedirs code is in common.py, around line 200 At the start is a line if not path or os.path.isdir(path): can you change "isdir" to "exists" so it reads if not path or os.path.exists(path): and report back. If that doesn't help I will rewrite it without using recursion and see if we can get to the bottom of it. Thanks.

philborman commented 6 years ago

Re debug levels: Levels over 2 are undefined and may be transient, I use them for focusing in on the more obscure errors, so to get at them you need to turn debugging on first, then increase the level.

kalo8450 commented 6 years ago

Made changes you suggested with same maximum recursion depth error.

2018-03-02 20:49:50 ERROR POSTPROCESS postprocess.py processDir 727 Postprocessing for PC Pro(2018-04-01) has failed: Unable to create directory K:\My Drive\Magazines\PC Pro: maximum recursion depth exceeded in cmp
2018-03-02 20:49:50 DEBUG POSTPROCESS postprocess.py processDestination 1232 K:\My Drive\Magazines\PC Pro does not exist, so it's safe to create it
philborman commented 6 years ago

ok, thanks for trying. We seem to be getting "doesn't exist" for things that do exist. What should happen (and does here) is the recursion stops as soon as we hit an existing directory. Your test changed this to exit as soon as we hit something that exists, directory or not.

K:\My Drive\Magazines\PC Pro does not exist, so we try next level up K:\My Drive\Magazines which does exist, so we should stop.

If the test fails we then try K:\My Drive and finally K For some reason we're not getting the right answer back from google drive file stream. I will need to think about it a bit.

philborman commented 6 years ago

ok, seems there are known problems with google file stream on windows drives: https://stackoverflow.com/questions/46104730/google-drive-file-stream-and-net-system-io-file-exists-a-case-sensitive-oddity Not sure if it's a case sensitivity issue in your case, but could be, maybe the drive is called 'k' and not 'K' or maybe the folder name cases are different. According to the link above google are working on it. We could probably work around it in lazylibrarian, but can we confirm if this is what the problem is somehow?

I could maybe put a small python program together to try it?

kalo8450 commented 6 years ago

Thanks for the update, I'm careful when dealing with any Linux based system to match case in path and file names just in case and can confirm that this has been adhered to but I'm happy to try anything you suggest.

I tried to add a new magazine, so the final directory does not exist and got this (different) error

2018-03-03 13:20:33 ERROR POSTPROCESS postprocess.py processDir 727 Postprocessing for BBC Knowledge(0007) has failed: Unable to create directory K:\My Drive\Magazines\BBC Knowledge: [Error 5] Access is denied: 'K:\My Drive'
2018-03-03 13:20:33 DEBUG POSTPROCESS postprocess.py processDestination 1232 K:\My Drive\Magazines\BBC Knowledge does not exist, so it's safe to create it
2018-03-03 13:20:33 DEBUG POSTPROCESS postprocess.py processDestination 1230 BookType: mag, calibredb: []
2018-03-03 13:20:33 DEBUG POSTPROCESS postprocess.py processDir 584 Processing magazine BBC Knowledge
2018-03-03 13:20:33 DEBUG POSTPROCESS postprocess.py processDir 543 Found match (100%): D:\Downloads\sabnzbd\complete\books\BBC Knowledge Asia Edition-Vol 7 for Magazine BBC.Knowledge.Asia.Edition-Vol.7
2018-03-03 13:20:33 DEBUG POSTPROCESS postprocess.py processDir 494 Found folder (100%) [D:\Downloads\sabnzbd\complete\books\BBC Knowledge Asia Edition-Vol 7] for Magazine BBC.Knowledge.Asia.Edition-Vol.7
2018-03-03 13:20:33 DEBUG POSTPROCESS postprocess.py processDir 438 processDir found u'D:\Downloads\sabnzbd\complete\books\BBC Knowledge Asia Edition-Vol 7'
2018-03-03 13:20:33 DEBUG POSTPROCESS postprocess.py processDir 433 100% match BBC.Knowledge.Asia.Edition-Vol.7 : BBC Knowledge Asia Edition-Vol 7
2018-03-03 13:20:33 DEBUG POSTPROCESS postprocess.py processDir 419 Checking extn on BBC Knowledge Asia Edition-Vol 7
philborman commented 6 years ago

No idea what's going on, just guessing really based on a quick web search. Seems google drive file stream doesn't behave how you would expect with windows filesystems. Might not be anything you can influence, might be interaction between the google virtual drive and the underlying windows filesystem. If so we're stuck until google fix it.

We could try a few tests if you don't mind running a bit of python in a windows terminal?

kalo8450 commented 6 years ago

Happy to

philborman commented 6 years ago

Great thanks. Here is a short python program to check what google drive is telling us. It uses a folder you tried to use earlier, and runs two tests, one with recursion and one without in case that's relevant. It should give us some info on what's failing. Hopefully by including the test for "tail" it shouldn't get stuck in the loop and hit the maximum recursion error.

import os
target ='K:\My Drive\Magazines\Practical Photoshop'

def walk(head):
  if not head:  # or os.path.exists(head):
        return
  print "Exists: ",os.path.exists(head), " Directory: ", os.path.isdir(head), head
  head, tail = os.path.split(head)
  if tail:
        walk(head)

print "Test 1, WHILE loop"
tail = True
head = target
while tail:
    print "Exists: ",os.path.exists(head), " Directory: ", os.path.isdir(head), head
    head, tail = os.path.split(head)

print "Test 2, recursion"
walk(target)
print "Test complete"
kalo8450 commented 6 years ago

As requested (eventually)

Test 1, WHILE loop Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Test 2, recursion Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Exists: True Directory: True K:\My Drive\Magazines Exists: True Directory: True K:\My Drive Exists: True Directory: True K:\ Exists: True Directory: True K:\My Drive\Magazines Test 2, recursion Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Exists: True Directory: True K:\My Drive\Magazines Exists: True Directory: True K:\My Drive Exists: True Directory: True K:\ Exists: True Directory: True K:\My Drive Test 2, recursion Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Exists: True Directory: True K:\My Drive\Magazines Exists: True Directory: True K:\My Drive Exists: True Directory: True K:\ Exists: True Directory: True K:\ Test 2, recursion Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Exists: True Directory: True K:\My Drive\Magazines Exists: True Directory: True K:\My Drive Exists: True Directory: True K:\ Test complete

kalo8450 commented 6 years ago

Oops, copied incorrectly from your email, this is the output from code above:

Test 1, WHILE loop Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Exists: True Directory: True K:\My Drive\Magazines Exists: True Directory: True K:\My Drive Exists: True Directory: True K:\ Test 2, recursion Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Exists: True Directory: True K:\My Drive\Magazines Exists: True Directory: True K:\My Drive Exists: True Directory: True K:\ Test complete

philborman commented 6 years ago

Well that's even more confusing, I presume the answers are correct, ie K:\My Drive\Magazines\Practical Photoshop is an existing directory?

Can you try adding a bit on the end and see what answers you get then, ie instead of starting at K:\My Drive\Magazines\Practical Photoshop start at K:\My Drive\Magazines\Practical Photoshop\level 1\level 2 where the extra levels of folders don't exist. Should hopefully get the right answers there too. If that's the case our problem seems to be making new directories, not checking for existing ones.

kalo8450 commented 6 years ago

Test 1, WHILE loop Exists: False Directory: False K:\My Drive\Magazines\Practical Photoshop\missing1\missing2 Exists: False Directory: False K:\My Drive\Magazines\Practical Photoshop\missing1 Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Exists: True Directory: True K:\My Drive\Magazines Exists: True Directory: True K:\My Drive Exists: True Directory: True K:\ Test 2, recursion Exists: False Directory: False K:\My Drive\Magazines\Practical Photoshop\missing1\missing2 Exists: False Directory: False K:\My Drive\Magazines\Practical Photoshop\missing1 Exists: True Directory: True K:\My Drive\Magazines\Practical Photoshop Exists: True Directory: True K:\My Drive\Magazines Exists: True Directory: True K:\My Drive Exists: True Directory: True K:\ Test complete

philborman commented 6 years ago

Ok many thanks. It's looking like a permissions problem creating the new directories. All the tests are working ok. I will need to add some more debugging code into the mymakedirs routine and get back to you.

philborman commented 6 years ago

One more test if you don't mind. Permissions testing. Based on the while loop that gave the right answers above...

import os
def mymakedirs(path):
    if not path or os.path.exists(path):
        return
    head, tail = os.path.split(path)
    if not tail:
        return
    mymakedirs(head)
    try:
        os.mkdir(path)
    except OSError:
        parent = os.path.split(path)[0]
        print "Parent: %s Mode: %s UID: %s GID: %s W_OK: %s X_OK: %s" % (parent,
                     oct(os.stat(parent).st_mode),
                     os.stat(parent).st_uid, os.stat(parent).st_gid,
                     os.access(parent, os.W_OK), os.access(parent, os.X_OK))
        raise

mymakedirs('K:\My Drive\Magazines\Practical Photoshop\missing1\missing2')

If this works and creates the new directories without error we will need to look at the permissions inside the lazylibrarian process itself.

kalo8450 commented 6 years ago

Works;) Creates both missing1 and missing1/missing2 no error messages

philborman commented 6 years ago

Oh no!, it wasn't supposed to ;-) I guess it's only a problem with permissions inside the lazylibrarian process then. The latest version of lazylibrarian (as of a few hours ago) includes exactly the same code I sent you, but if you turn debug level up to 3 you will get a very detailed message if it can't create a folder. It may even work inside lazylibrarian too now, if we're really lucky.

kalo8450 commented 6 years ago

Still unable to create folder. LL fully up to date debug level 3 and saved.

2018-03-10 13:42:32 WARNING POSTPROCESS postprocess.py processDir 748 Residual files remain in D:\Downloads\sabnzbd\complete\books\Stereophile TruePDF-February 2018.fail
2018-03-10 13:42:32 ERROR POSTPROCESS postprocess.py processDir 727 Postprocessing for stereophile(2018-02-01) has failed: Unable to create directory K:\My Drive\Magazines\stereophile: [Error 5] Access is denied: 'K:\'
2018-03-10 13:42:32 DEBUG POSTPROCESS postprocess.py processDestination 1233 K:\My Drive\Magazines\stereophile does not exist, so it's safe to create it
2018-03-10 13:42:32 DEBUG POSTPROCESS postprocess.py processDestination 1231 BookType: mag, calibredb: []
2018-03-10 13:42:32 DEBUG POSTPROCESS postprocess.py processDir 584 Processing magazine stereophile
philborman commented 6 years ago

Ok, a bit weird. The "Error 5" is a windows error, not from python. Seems the underlying windows driver is refusing us access to K: See the following link and let me know if it helps. I think the python program thinks it has permission but the windows subsystem says no... https://appuals.com/fix-error-5-access-denied-windows-10/

philborman commented 6 years ago

As this doesn't seem to be anything we can influence within LazyLibrarian I have removed the test/debugging code and reverted to previous method.

kalo8450 commented 6 years ago

Tried each of the methods in the link finishing by enabling the Administrator account, removing File Stream, rebooting, logging on as Administrator and reinstalling File Stream. Nothing worked, still getting the "Error 5".

philborman commented 6 years ago

I'm out of ideas on this, but it doesn't seem to be a lazylibrarian issue as such, and we can't find a work-around for it either. I will leave the issue open and see if anyone else can shed any light on it. Unfortunately I am unable to test directly as I run on linux, and File Stream is currently windows/mac only.

kalo8450 commented 6 years ago

Thanks for trying.

philborman commented 6 years ago

No problem, I enjoy the challenge, but more so when it's successful.

philborman commented 6 years ago

There are some recent changes to directory creation in lazylibrarian that may have helped with this, or not, hard to tell.

kalo8450 commented 6 years ago

I gave it a try - sill no joy but a different error message.

2018-04-24 16:20:20 ERROR Unhandled exception in processDir: Traceback (most recent call last): File "D:\GitHub\LazyLibrarian\lazylibrarian\postprocess.py", line 694, in processDir global_name, book['BookID'], book_type) File "D:\GitHub\LazyLibrarian\lazylibrarian\postprocess.py", line 1385, in processDestination return False, 'Unable to create directory %s: %s' % dest_path TypeError: not enough arguments for format string
2018-04-24 16:20:20 ERROR Unable to create directory G:\: [Error 5] Access is denied: 'G:\'
philborman commented 6 years ago

ok, thanks for trying. Fixed the format string error, but that won't solve the underlying problem. We think none of the intermediate directories exist and end up going right back to G:

philborman commented 6 years ago

Development has moved to GitLab All open issues have been moved over to LazyLibrarian Issues Please open any new issues or comments on the new repo as the old one is no longer maintained, thanks