There are 87400 items to parse and the current inodeTree size is 0 - inodeTree in cache not finishing on Mac

[ecchi]

Didn't immediately notice this because I had an existing cache on another computer that was somewhat up to date, and works with this latest build. But uploading is problematic because its so out of date.

When installing on new Mac, and downloading cache for very first time (or deleting existing cache and re-indexing all over again), it never completes and never mounts.

The debug:

2015-11-12T22:26::30 - debug: current length of items during downloading of all files is 92962
2015-11-12T22:26::30 - debug: saving folder tree
2015-11-12T22:26::33 - debug: Starting to parse items from google.
2015-11-12T22:26::33 - debug: There are 5000  items to parse and the current inodeTree size is 0.
2015-11-12T22:26::33 - info: Parinsg data, looking for root foolder
2015-11-12T22:26::33 - info: Folders left to parse: 254
2015-11-12T22:26::33 - info: There was 254 folders that were not possible to process
2015-11-12T22:26::33 - info: Parsing files
2015-11-12T22:26::33 - debug: After attempting to parse, there is 0 items in the inodeTree and 5000 items that were not yet parseable
2015-11-12T22:26::35 - debug: Starting to parse items from google.
2015-11-12T22:26::35 - debug: There are 10000  items to parse and the current inodeTree size is 0.

eventually grows to:

2015-11-12T22:27::14 - debug: After attempting to parse, there is 0 items in the inodeTree and 85000 items that were not yet parseable
2015-11-12T22:27::17 - debug: Starting to parse items from google.
2015-11-12T22:27::17 - debug: There are 87400  items to parse and the current inodeTree size is 0.
2015-11-12T22:27::17 - info: Parinsg data, looking for root foolder
2015-11-12T22:27::18 - info: Folders left to parse: 254
2015-11-12T22:27::18 - info: There was 254 folders that were not possible to process
2015-11-12T22:27::18 - info: Parsing files
2015-11-12T22:27::18 - debug: After attempting to parse, there is 0 items in the inodeTree and 87400 items that were not yet parseable

until it loops to this:

2015-11-12T22:28::0 - debug: Getting changes from Google Drive. The last change id was 537241.
2015-11-12T22:28::0 - debug: There was 0 to parse
2015-11-12T22:28::0 - debug: Finished parsing changes from google
2015-11-12T22:29::11 - debug: Getting changes from Google Drive. The last change id was 537241.
2015-11-12T22:29::11 - debug: There was 0 to parse

My inodeTree.json in cache/data ends up empty. my sqlite.db has 87400 rows though and is 48MB.

Using an older cache, I can view the old content fine. Newer content is missing from the index, and any attempts to upload fail.

2015-11-12T23:5::6 - debug: Getting changes from Google Drive. The last change id was 537241.
2015-11-12T23:5::6 - debug: There was 0 to parse
2015-11-12T23:5::6 - debug: Finished parsing changes from google
2015-11-12T23:5::12 - debug: creating file XYZe06epname.mp4
2015-11-12T23:5::12 - debug: adding file "XYZe06epname.mp4" to folder "Season 01"
2015-11-12T23:5::12 - debug: saving folder tree
2015-11-12T23:5::12 - debug: create: parentid: 0B5KaEXAMPLE -- inode 7948
2015-11-12T23:5::12 - info: adding a new file XYZe06epname.mp4 to folder Season 01
2015-11-12T23:5::12 - debug: setting upload Tree
2015-11-12T23:5::12 - debug: saving upload tree
2015-11-12T23:5::12 - debug: 7948 was in the upload tree
2015-11-12T23:5::12 - debug: removing file XYZe06epname.mp4
2015-11-12T23:5::12 - debug: saving folder tree
2015-11-12T23:5::13 - debug: unable to remove file XYZe06epname.mp4
2015-11-12T23:5::13 - debug: creating file XYZe06epname.mp4
2015-11-12T23:5::13 - debug: adding file "XYZe06epname.mp4" to folder "Season 01"
2015-11-12T23:5::13 - debug: saving folder tree
2015-11-12T23:5::13 - debug: create: parentid: 0B5KaEXAMPLE -- inode 7949
2015-11-12T23:5::13 - info: adding a new file XYZe06epname.mp4 to folder Season 01
2015-11-12T23:5::13 - debug: setting upload Tree
2015-11-12T23:5::13 - debug: saving upload tree
2015-11-12T23:5::39 - debug: 7949 was in the upload tree
2015-11-12T23:5::39 - debug: saving upload tree
2015-11-12T23:5::39 - debug: setting attr for 7949
2015-11-12T23:5::39 - debug: mode before and after: 33279-33188
2015-11-12T23:5::41 - debug: starting to download XYZe09.epname9.mp4, chunkStart: 0
2015-11-12T23:5::44 - info: Starting to upload file XYZe06epname.mp4 
2015-11-12T23:5::45 - debug: saving upload tree
2015-11-12T23:6::3 - info: resuming file uploading
2015-11-12T23:6::3 - debug: saving upload tree
2015-11-12T23:6::8 - debug: saving upload tree
2015-11-12T23:6::8 - info: Starting to upload file XYZe06epname.mp4 
2015-11-12T23:6::8 - debug: got new range end for 7949: 10485759
2015-11-12T23:6::16 - error: error after piping
2015-11-12T23:6::16 - error:  code=EPIPE, errno=EPIPE, syscall=write, address=undefined
2015-11-12T23:6::19 - debug: Getting changes from Google Drive. The last change id was 537241.

eventually loops to this, and the mount says there are zero bytes for the file when trying to playback.

2015-11-12T23:6::19 - debug: There was 0 to parse
2015-11-12T23:6::19 - debug: Finished parsing changes from google

Mac OSX 10.10.5 and 10.11.1, osxfuse 2.8.2, node 5.0, pkg-config 0.29, concurrencykit 0.50

[wnielson]

I'm seeing very similar behavior. I can really only see the folders in the root directory, and they are mostly empty.

[EricTheMagician]

@wnielson are you on osx as well?
You guys can maybe checkout the upload_refactor branch, it does have some fixes, but I'm not sure if it will address all of your issues. Right now I'm trying to track down a bug where if you use "du" on the root folder, it works, but if you do it twice in parallel, it kills the filesystem and it seems like it's always been an issue.

[wnielson]

No, I'm using Ubuntu. I'll try the refactor branch today.

On Fri, Nov 13, 2015 at 6:51 AM Eric Yen [email protected] wrote:

@wnielson https://github.com/wnielson are you on osx as well?
You guys can maybe checkout the upload_refactor branch, it does have some
fixes, but I'm not sure if it will address all of your issues. Right now
I'm trying to track down a bug where if you use "du" on the root folder, it
works, but if you do it twice in parallel, it kills the filesystem and it
seems like it's always been an issue.

—
Reply to this email directly or view it on GitHub
#87 (comment)
.

[ecchi]

Trying upload_refactor branch. On fresh cache (re-index).
It "appears" to mount. But when I do browse with finder, I can't dive into it. Nor in terminal I can't

ls ~/mnt
Permission denied
sudo ls ~/mnt
Permission denied

After I kill node, I can still diskutil unmount ~/mnt and it succeeds. Strange.

[wnielson]

No go for me either--same behavior as before.

[EricTheMagician]

Are you guys running it as root by any chance?

[wnielson]

Yes, I am running it as root.

[wnielson]

Just tried it as a regular user without any luck.

[wnielson]

To test some more, I did a fresh checkout on my Mac. As a normal user, I installed NodeJS v4.2.2 via nvm. Running node fs.es6.js yields the same behavior. I can see the folders contained in the root directory, but everything is empty. FYI, here is the output:

wBook:src wnielson$ node fs.es6.js 
2015-11-14T17:46::14 - info: Access Token Set
2015-11-14T17:46::14 - debug: Folder tree exist status: false
2015-11-14T17:46::14 - info: Downloading full folder structure from google
2015-11-14T17:46::14 - info: Opened a connection to the database
2015-11-14T17:46::16 - debug: current length of items during downloading of all files is 460
2015-11-14T17:46::18 - debug: current length of items during downloading of all files is 920
2015-11-14T17:46::19 - debug: current length of items during downloading of all files is 1380
2015-11-14T17:46::21 - debug: current length of items during downloading of all files is 1840
2015-11-14T17:46::23 - debug: current length of items during downloading of all files is 2300
2015-11-14T17:46::25 - debug: current length of items during downloading of all files is 2760
2015-11-14T17:46::27 - debug: current length of items during downloading of all files is 3220
2015-11-14T17:46::29 - debug: current length of items during downloading of all files is 3680
2015-11-14T17:46::30 - debug: current length of items during downloading of all files is 4140
2015-11-14T17:46::32 - debug: current length of items during downloading of all files is 4600
2015-11-14T17:46::35 - debug: current length of items during downloading of all files is 5060
2015-11-14T17:46::36 - debug: current length of items during downloading of all files is 5520
2015-11-14T17:46::38 - debug: current length of items during downloading of all files is 5802
2015-11-14T17:46::38 - debug: saving folder tree
2015-11-14T17:46::38 - debug: Starting to parse items from google.
2015-11-14T17:46::38 - debug: There are 5000  items to parse and the current inodeTree size is 0.
2015-11-14T17:46::38 - info: Parinsg data, looking for root foolder
2015-11-14T17:46::38 - debug: saving folder tree
2015-11-14T17:46::38 - info: root node found
2015-11-14T17:46::38 - info: Folders left to parse: 250
2015-11-14T17:46::38 - info: Folders left to parse: 244
2015-11-14T17:46::38 - info: Folders left to parse: 243
2015-11-14T17:46::38 - info: There was 243 folders that were not possible to process
2015-11-14T17:46::38 - info: Parsing files
2015-11-14T17:46::38 - debug: After attempting to parse, there is 10 items in the inodeTree and 4991 items that were not yet parseable
2015-11-14T17:46::38 - debug: Starting to parse items from google.
2015-11-14T17:46::38 - debug: There are 5038  items to parse and the current inodeTree size is 10.
2015-11-14T17:46::38 - info: Parinsg data
2015-11-14T17:46::38 - info: Folders left to parse: 243
2015-11-14T17:46::38 - info: There was 243 folders that were not possible to process
2015-11-14T17:46::38 - info: Parsing files
2015-11-14T17:46::38 - debug: saving folder tree
2015-11-14T17:46::38 - debug: After attempting to parse, there is 10 items in the inodeTree and 5038 items that were not yet parseable
2015-11-14T17:46::38 - debug: saving folder tree
2015-11-14T17:46::38 - info: attempting to start f4js
2015-11-14T17:46::38 - info: unmounting output: Unmount successful for /tmp/mnt

2015-11-14T17:46::38 - info: mount point: /tmp/mnt

[EricTheMagician]

I looked at things more closely and there are two separate errors

@ecchi
The problem for you is that there was probably an error while inserting items in the database.
So the one that probably failed is the one that had the root folder, and that's why the number files that couldn't be inserted grew so large.

And unfortunately, when there was an error, it wasn't handling it properly. So you will have to delete "inodeTree.json" from the cache and let it download all again.

@wnielson
So I tried it on my mac. I was able to reproduce the error.
I think the issue stemmed from the timing of the first loading of the files. I think you would have been fine if you had restarted.

[wnielson]

@thejinx0r I've tried restarting fs.es6.js multiple times to no avail.

[EricTheMagician]

@wnielson
Can you open a new issue?
Can you try clearing the inode tree and let it download again?

[ecchi]

deleted my inode tree, pulled latest(upload_refactor) and did node fs.es6.js:

2015-11-19T0:30::5 - debug: current length of items during downloading of all files is 87334
2015-11-19T0:30::8 - debug: current length of items during downloading of all files is 87794
/Users/ecchi/Code/node-gdrive-fuse/src/client.es6.js:109
                if(resp.items.length > 0){
                   ^

ReferenceError: resp is not defined
    at insertInToDBFromParsingFiles (/Users/ecchi/Code/node-gdrive-fuse/src/client.es6.js:109:20)
    at Statement.errBack (/Users/ecchi/Code/node-gdrive-fuse/node_modules/sqlite3/lib/sqlite3.js:16:21)

[wnielson]

I had some time to play around with this today and I think I've figured out how to get things to work properly. I edited largestChangeId.json and set largestChangeId to 0 and then restarted fs.es6.js. After that, the missing files and folders are found and everything appears to be working correctly. I tested this on both OS X and Ubuntu using node 4.2.2.

[ecchi]

editing largestChangeId.json did not help my situation. I've tried every variation of node, linux, osx, and git pulls and branches and its still in this broken state. My only conclusion at this time is my google drive is overly complex with near 100,000 items, from Arq back-ups, and work documents, spread over a labyrinth of folders and sub-folders. The only suggestion I have for the jinx0r is maybe make node-gdrive-fuse mount a specific "bucket" or folder instead, and ignore everything else. I'm slowly moving stuff to ACD, just so I can mount my data again.