After updating to latest beta application can't see the files

random404 · April 1, 2020, 9:07pm

I just updated to rclone beta v1.51.0-148 and now applications can't see any files anymore!

I have opened shell as the user and I can interact with the files but it doesn't work on my application anymore.

I'm using a union remote. Any ideas?

calisro · April 1, 2020, 10:41pm

You need to fill in the question template with debug logs. Otherwise everyone is guessing.

asdffdsa · April 1, 2020, 10:49pm

What is the problem you are having with rclone?

What is your rclone version (output from `rclone version`)

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Which cloud storage system are you using? (eg Google Drive)

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

A log from the command with the `-vv` flag (eg output from `rclone -vv copy /tmp remote:tmp`)

random404 · April 2, 2020, 9:47am

The problem is...I have lots of concurrently usage on the mount so the logs will just be spammed infinitely...but I'll try to get something useful and get back here

random404 · April 2, 2020, 10:30am

So to be clear, the mount is working when the application is reading files it already acessed before, but it can't see new files. It's a php web interface that list files in a directory.

I created a folder structure like this: processing/Test (2013)/Test (2013).mkv where Test (2013).mkv is a 17 MB file and tried to access it using the web interface - that always worked fine before.

I enabled --loglevel DEBUG and tried to scan the folder using the web interface and filtered the log file with cat /opt/rclone.log | grep "Test (2013)":

2020/04/02 07:11:29 DEBUG : processing/: Lookup: name="Test (2013)"
2020/04/02 07:11:30 DEBUG : processing/: >Lookup: node=processing/Test (2013)/, err=<nil>
2020/04/02 07:11:30 DEBUG : processing/Test (2013)/: Attr: 
2020/04/02 07:11:30 DEBUG : processing/Test (2013)/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2020/04/02 07:11:30 DEBUG : processing/Test (2013)/: ReadDirAll: 
2020/04/02 07:11:30 DEBUG : processing/Test (2013)/: >ReadDirAll: item=1, err=<nil>
2020/04/02 07:11:32 DEBUG : processing/: Lookup: name="Test (2013)"
2020/04/02 07:11:32 DEBUG : processing/: >Lookup: node=processing/Test (2013)/, err=<nil>
2020/04/02 07:11:32 DEBUG : processing/Test (2013)/: Attr: 
2020/04/02 07:11:32 DEBUG : processing/Test (2013)/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2020/04/02 07:11:32 DEBUG : processing/Test (2013)/: ReadDirAll: 
2020/04/02 07:11:32 DEBUG : processing/Test (2013)/: >ReadDirAll: item=1, err=<nil>

It's like it never see the files there.... but I can mediainfo the file just fine via shell:

2020/04/02 07:17:54 DEBUG : processing/: Lookup: name="Test (2013)"
2020/04/02 07:17:54 DEBUG : processing/: >Lookup: node=processing/Test (2013)/, err=<nil>
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/: Attr: 
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/: ReadDirAll: 
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/: >ReadDirAll: item=1, err=<nil>
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/: Lookup: name="Test (2013).mkv"
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/: >Lookup: node=processing/Test (2013)/Test (2013).mkv, err=<nil>
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: Attr: 
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: >Attr: a=valid=1s ino=0 size=17601927 mode=-rw-rw-r--, err=<nil>
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: Open: flags=OpenReadOnly
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: Open: flags=O_RDONLY
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: >Open: fd=processing/Test (2013)/Test (2013).mkv (r), err=<nil>
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: >Open: fh=&{processing/Test (2013)/Test (2013).mkv (r)}, err=<nil>
2020/04/02 07:17:54 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Flush: 
2020/04/02 07:17:54 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Flush: err=<nil>
2020/04/02 07:17:54 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Release: 
2020/04/02 07:17:54 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Release: err=<nil>
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: Open: flags=OpenReadOnly
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: Open: flags=O_RDONLY
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: >Open: fd=processing/Test (2013)/Test (2013).mkv (r), err=<nil>
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: >Open: fh=&{processing/Test (2013)/Test (2013).mkv (r)}, err=<nil>
2020/04/02 07:17:54 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=0
2020/04/02 07:17:54 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.openRange at 0 length 10485760
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 0 length 131072 chunkOffset 0 chunkSize 10485760
2020/04/02 07:17:55 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: Open: flags=OpenReadOnly
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: Open: flags=O_RDONLY
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: >Open: fd=processing/Test (2013)/Test (2013).mkv (r), err=<nil>
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: >Open: fh=&{processing/Test (2013)/Test (2013).mkv (r)}, err=<nil>
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: Attr: 
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: >Attr: a=valid=1s ino=0 size=17601927 mode=-rw-rw-r--, err=<nil>
2020/04/02 07:17:55 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Flush: 
2020/04/02 07:17:55 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Flush: err=<nil>
2020/04/02 07:17:55 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Release: 
2020/04/02 07:17:55 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Release: err=<nil>
2020/04/02 07:17:55 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=131072
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 131072 length 131072 chunkOffset 0 chunkSize 10485760
2020/04/02 07:17:55 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:55 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=4096, offset=65536
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: ReadFileHandle.seek from 262144 to 65536 (fs.RangeSeeker)
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.RangeSeek from 262144 to 65536 length -1
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at -1 length 4096 chunkOffset 65536 chunkSize 10485760
2020/04/02 07:17:55 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.openRange at 65536 length 10485760
2020/04/02 07:17:56 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=4096, err=<nil>
2020/04/02 07:17:56 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=61440, offset=69632
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 69632 length 61440 chunkOffset 65536 chunkSize 10485760
2020/04/02 07:17:56 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=61440, err=<nil>
2020/04/02 07:17:56 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=262144
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: waiting for in-sequence read to 262144 for 5ms
2020/04/02 07:17:56 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=393216
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: waiting for in-sequence read to 393216 for 5ms
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: aborting in-sequence read wait, off=262144
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: waiting for in-sequence read to 393216 for 5ms
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: failed to wait for in-sequence read to 262144
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: ReadFileHandle.seek from 131072 to 262144 (fs.RangeSeeker)
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.RangeSeek from 131072 to 262144 length -1
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at -1 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.openRange at 262144 length 10485760
2020/04/02 07:17:56 DEBUG : processing/Test (2013)/Test (2013).mkv: aborting in-sequence read wait, off=393216
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 393216 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: Attr: 
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: >Attr: a=valid=1s ino=0 size=17601927 mode=-rw-rw-r--, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=524288
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 524288 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=655360
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 655360 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=786432
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 786432 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=917504
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 917504 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=1048576
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 1048576 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=1179648
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 1179648 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=131072, offset=1310720
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at 1310720 length 131072 chunkOffset 262144 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=131072, err=<nil>
2020/04/02 07:17:57 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Read: len=8192, offset=17596416
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ReadFileHandle.seek from 1441792 to 17596416 (fs.RangeSeeker)
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.RangeSeek from 1441792 to 17596416 length -1
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.Read at -1 length 8192 chunkOffset 17596416 chunkSize 10485760
2020/04/02 07:17:57 DEBUG : processing/Test (2013)/Test (2013).mkv: ChunkedReader.openRange at 17596416 length 10485760
2020/04/02 07:17:58 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Read: read=5511, err=<nil>
2020/04/02 07:17:58 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Flush: 
2020/04/02 07:17:58 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Flush: err=<nil>
2020/04/02 07:17:58 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: Release: 
2020/04/02 07:17:58 DEBUG : processing/Test (2013)/Test (2013).mkv: ReadFileHandle.Release closing
2020/04/02 07:17:58 DEBUG : &{processing/Test (2013)/Test (2013).mkv (r)}: >Release: err=<nil>

What's weird is that even rolling back to the version I used before doesn't work too and nothing changed. I'm out of ideas

ncw · April 2, 2020, 7:04pm

You might need to edit your config file to change upstreams back into remotes to get it to work again.

So do you see the files if you ls the mount?

If so it must be some interaction between the PHP app and rclone? Did you restart the PHP app? Maybe you have overmounted rclone and the PHP app is looking at the old mount...

system · June 2, 2020, 3:05pm

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.