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

ls: Input/output error #161

Open
zyxmon opened this issue Jul 6, 2016 · 10 comments
Open

ls: Input/output error #161

zyxmon opened this issue Jul 6, 2016 · 10 comments

Comments

@zyxmon
Copy link

zyxmon commented Jul 6, 2016

I have build GDriveFS for Entware - https://github.com/Entware-ng/Entware-ng
(I have used pip install for testing).
fuse mount seems to work gdfs(/opt/var/cache/gdfs.creds) on /opt/gdrive type fuse (rw,nosuid,nodev,relatime,user_id=0,group_id=0)
When I try to access mounted folder I have Input/output error.
Here is a debug log

>GD_DEBUG=1 gdfs /opt/var/cache/gdfs.creds /opt/gdrive
2016-07-06 06:42:14,275 [gdrivefs.utility INFO] No extension-mapping was found.
2016-07-06 06:42:14,611 [__main__ DEBUG] Mounting GD with creds at [/opt/var/cache/gdfs.creds]: /opt/gdrive
2016-07-06 06:42:14,615 [gdrivefs.gdfs.gdfuse DEBUG] FUSE options:
{}
2016-07-06 06:42:14,619 [gdrivefs.gdfs.gdfuse DEBUG] PERMS: F=777 E=666 NE=444
2016-07-06 06:42:14,673 [gdrivefs.gdtool.oauth_authorize INFO] Credentials have expired. Attempting to refresh them.
2016-07-06 06:42:14,675 [gdrivefs.gdtool.oauth_authorize INFO] Doing credentials refresh.
2016-07-06 06:42:14,679 [oauth2client.client INFO] Refreshing access_token
2016-07-06 06:42:15,282 [gdrivefs.gdtool.drive DEBUG] Getting authorized HTTP tunnel.
2016-07-06 06:42:15,287 [gdrivefs.gdtool.drive DEBUG] Got authorized tunnel.
FUSE library version: 2.9.3
nullpath_ok: 0
nopath: 0
utime_omit_ok: 0
unique: 1, opcode: INIT (26), nodeid: 0, insize: 56, pid: 0
INIT: 7.18
flags=0x0000047b
max_readahead=0x00020000
2016-07-06 06:42:16,522 [gdrivefs.gdfs.fsutility DEBUG] --------------------------------------------------
2016-07-06 06:42:16,524 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>> init(23) >>>>>>>>>> (0)
2016-07-06 06:42:16,528 [gdrivefs.gdfs.fsutility DEBUG] DATA: path= [/]
2016-07-06 06:42:16,530 [gdrivefs.gdfs.gdfuse INFO] Activating change-monitor.
2016-07-06 06:42:16,876 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<< init(23) (0)
2016-07-06 06:42:16,879 [gdrivefs.gdtool.drive DEBUG] Getting authorized HTTP tunnel.
2016-07-06 06:42:16,883 [gdrivefs.gdtool.drive DEBUG] Got authorized tunnel.
   INIT: 7.19
   flags=0x00000011
   max_readahead=0x00020000
   max_write=0x00020000
   max_background=0
   congestion_threshold=0
   unique: 1, success, outsize: 40
unique: 2, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 10738
getattr /
2016-07-06 06:42:43,640 [gdrivefs.gdfs.fsutility DEBUG] --------------------------------------------------
2016-07-06 06:42:43,642 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>> getattr(4) >>>>>>>>>> (10738)
2016-07-06 06:42:43,644 [gdrivefs.gdfs.fsutility DEBUG] DATA: fh= [None]  raw_path= [/]
2016-07-06 06:42:43,659 [gdrivefs.cache.cacheclient_base DEBUG] CacheClientBase(CacheClientBase,28800)
2016-07-06 06:42:43,662 [gdrivefs.cache.cache_agent INFO] Starting cache-cleanup thread: <gdrivefs.cache.cache_agent.CacheAgent object at 0xf65858>
2016-07-06 06:42:43,670 [gdrivefs.cache.cache_agent INFO] Cache-cleanup thread running: <gdrivefs.cache.cache_agent.CacheAgent object at 0xf65858>
2016-07-06 06:42:43,669 [gdrivefs.gdtool.drive INFO] Getting client for parent-listing.
2016-07-06 06:42:43,675 [gdrivefs.gdtool.drive INFO] Listing entries over child with ID [0AP09GPqvAIMZUk9PVA].
2016-07-06 06:42:44,902 [gdrivefs.gdtool.drive DEBUG] (1) entries were retrieved.
2016-07-06 06:42:44,908 [gdrivefs.cache.volume DEBUG] Recursively pruning entry with ID [0AP09GPqvAIMZUk9PVA].
2016-07-06 06:42:44,928 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<< getattr(4) (10738)
   unique: 2, success, outsize: 120

I am running it on a mipsel device where part of the filesystem is read only. May be it is cache issue?

BTW I have no problems running davfs2, encfs on this router.

@dsoprea
Copy link
Owner

dsoprea commented Jul 6, 2016

I'm not familiar with mipsel. Which part of the filesystem is readonly?
Writes will only be performed on the tmpfs mount, whereever that happens
to be.

If you get an error during access, there will be an error in the log.
Almost all of the slice that you provided is the standard stuff following a
mount. There has to be more.

On Tue, Jul 5, 2016 at 11:59 PM, zyxmon notifications@github.com wrote:

I have build GDriveFS for Entware -
https://github.com/Entware-ng/Entware-ng
(I have used pip install for testing).
fuse mount seems to work gdfs(/opt/var/cache/gdfs.creds) on /opt/gdrive
type fuse (rw,nosuid,nodev,relatime,user_id=0,group_id=0)
When I try to access mounted folder I have Input/output error.
Here is a debug log

GD_DEBUG=1 gdfs /opt/var/cache/gdfs.creds /opt/gdrive
2016-07-06 06:42:14,275 [gdrivefs.utility INFO] No extension-mapping was found.
2016-07-06 06:42:14,611 [main DEBUG] Mounting GD with creds at [/opt/var/cache/gdfs.creds]: /opt/gdrive
2016-07-06 06:42:14,615 [gdrivefs.gdfs.gdfuse DEBUG] FUSE options:
{}
2016-07-06 06:42:14,619 [gdrivefs.gdfs.gdfuse DEBUG] PERMS: F=777 E=666 NE=444
2016-07-06 06:42:14,673 [gdrivefs.gdtool.oauth_authorize INFO] Credentials have expired. Attempting to refresh them.
2016-07-06 06:42:14,675 [gdrivefs.gdtool.oauth_authorize INFO] Doing credentials refresh.
2016-07-06 06:42:14,679 [oauth2client.client INFO] Refreshing access_token
2016-07-06 06:42:15,282 [gdrivefs.gdtool.drive DEBUG] Getting authorized HTTP tunnel.
2016-07-06 06:42:15,287 [gdrivefs.gdtool.drive DEBUG] Got authorized tunnel.
FUSE library version: 2.9.3
nullpath_ok: 0
nopath: 0
utime_omit_ok: 0
unique: 1, opcode: INIT (26), nodeid: 0, insize: 56, pid: 0
INIT: 7.18
flags=0x0000047b
max_readahead=0x00020000
2016-07-06 06:42:16,522 [gdrivefs.gdfs.fsutility DEBUG] --------------------------------------------------
2016-07-06 06:42:16,524 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>> init(23) >>>>>>>>>> (0)
2016-07-06 06:42:16,528 [gdrivefs.gdfs.fsutility DEBUG] DATA: path= [/]
2016-07-06 06:42:16,530 [gdrivefs.gdfs.gdfuse INFO] Activating change-monitor.
2016-07-06 06:42:16,876 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<< init(23) (0)
2016-07-06 06:42:16,879 [gdrivefs.gdtool.drive DEBUG] Getting authorized HTTP tunnel.
2016-07-06 06:42:16,883 [gdrivefs.gdtool.drive DEBUG] Got authorized tunnel.
INIT: 7.19
flags=0x00000011
max_readahead=0x00020000
max_write=0x00020000
max_background=0
congestion_threshold=0
unique: 1, success, outsize: 40
unique: 2, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 10738
getattr /
2016-07-06 06:42:43,640 [gdrivefs.gdfs.fsutility DEBUG] --------------------------------------------------
2016-07-06 06:42:43,642 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>> getattr(4) >>>>>>>>>> (10738)
2016-07-06 06:42:43,644 [gdrivefs.gdfs.fsutility DEBUG] DATA: fh= [None] raw_path= [/]
2016-07-06 06:42:43,659 [gdrivefs.cache.cacheclient_base DEBUG] CacheClientBase(CacheClientBase,28800)
2016-07-06 06:42:43,662 [gdrivefs.cache.cache_agent INFO] Starting cache-cleanup thread: <gdrivefs.cache.cache_agent.CacheAgent object at 0xf65858>
2016-07-06 06:42:43,670 [gdrivefs.cache.cache_agent INFO] Cache-cleanup thread running: <gdrivefs.cache.cache_agent.CacheAgent object at 0xf65858>
2016-07-06 06:42:43,669 [gdrivefs.gdtool.drive INFO] Getting client for parent-listing.
2016-07-06 06:42:43,675 [gdrivefs.gdtool.drive INFO] Listing entries over child with ID [0AP09GPqvAIMZUk9PVA].
2016-07-06 06:42:44,902 gdrivefs.gdtool.drive DEBUG entries were retrieved.
2016-07-06 06:42:44,908 [gdrivefs.cache.volume DEBUG] Recursively pruning entry with ID [0AP09GPqvAIMZUk9PVA].
2016-07-06 06:42:44,928 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<< getattr(4) (10738)
unique: 2, success, outsize: 120

I am running it on a mipsel device where part of the filesystem is read
only. May be it is cache issue?

BTW I have no problems running davfs2, encfs on this router.


You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
#161, or mute the thread
https://github.com/notifications/unsubscribe/AArralrxvgG3UBM6AhNQ2XF47reM3QNlks5qSygOgaJpZM4JFvCc
.

@zyxmon
Copy link
Author

zyxmon commented Jul 6, 2016

rootfs is RO.
/tmp /var are tmpfs
/opt is a usb drive where gdrivefs is installed.
Nothing more in the log after ls <mountpoint> in another terminal.

@dsoprea
Copy link
Owner

dsoprea commented Jul 6, 2016

Unmount and remount, then. Try the following until something produces an
error:

  1. ls from outside the mount (twice).
  2. ls from inside the mount (on ".", twice).
  3. ls a specific member.
  4. From the mountpoint, change into a child directory and do another ls.
  5. Do a copy from outside the mount into the mount.
  6. ls what you copied.
  7. Do a delete of what you copied.
  8. Unmount.

On Wed, Jul 6, 2016 at 12:47 AM, zyxmon notifications@github.com wrote:

rootfs is RO.
/tmp /var are tmpfs
/opt is a usb drive where gdrivefs is installed.
Nothing more in the log after ls in another terminal.


You are receiving this because you commented.
Reply to this email directly, view it on GitHub
#161 (comment),
or mute the thread
https://github.com/notifications/unsubscribe/AArrajYsdyo0bqD2TPFgF7IFvVYzoi8sks5qSzNOgaJpZM4JFvCc
.

@zyxmon
Copy link
Author

zyxmon commented Jul 6, 2016

After the first Input/Output error mount point is displayed with a question mark a a first char.
All operation with it produce Input/Output error and no debug log.
I had similar behavior with encfs. Upgrading encfs solved the problem.

@dsoprea
Copy link
Owner

dsoprea commented Jul 6, 2016

You're not aware of the use of any non-English-friendly character sets in
file naming are you (not that that'd necessarily cause a problem)?

On Wed, Jul 6, 2016 at 1:09 AM, zyxmon notifications@github.com wrote:

After the first Input/Output error mount point is displayed with a
question mark a a first char.
All operation with it produce Input/Output error and no debug log.
I had similar behavior with encfs. Upgrading encfs solved the problem.


You are receiving this because you commented.
Reply to this email directly, view it on GitHub
#161 (comment),
or mute the thread
https://github.com/notifications/unsubscribe/AArram24Xibn5QY1Zmmc57cAkCi14wv-ks5qSzh0gaJpZM4JFvCc
.

@dsoprea
Copy link
Owner

dsoprea commented Jul 6, 2016

Another two options:

  1. Try it in Vagrant using the included Vagrant file.
  2. Start it in the foreground and in debug mode. Note that you'll likely
    have to unmount and then SIGHUP it to shut it down. Example:

GD_DEBUG=1 GD_MONITOR_CHANGES=0 gdfs /var/cache/gdfs.creds /mnt/g

Dustin

On Wed, Jul 6, 2016 at 1:12 AM, Dustin Oprea myselfasunder@gmail.com
wrote:

You're not aware of the use of any non-English-friendly character sets in
file naming are you (not that that'd necessarily cause a problem)?

On Wed, Jul 6, 2016 at 1:09 AM, zyxmon notifications@github.com wrote:

After the first Input/Output error mount point is displayed with a
question mark a a first char.
All operation with it produce Input/Output error and no debug log.
I had similar behavior with encfs. Upgrading encfs solved the problem.


You are receiving this because you commented.
Reply to this email directly, view it on GitHub
#161 (comment),
or mute the thread
https://github.com/notifications/unsubscribe/AArram24Xibn5QY1Zmmc57cAkCi14wv-ks5qSzh0gaJpZM4JFvCc
.

@zyxmon
Copy link
Author

zyxmon commented Jul 6, 2016

All the files and folders are ansi (english).
There is no vagrant. I need to build it in Entware. I test gdrivefs on an embeded mipsel router with 128MB of ram and 700Mhz mipsel cpu. Nearly all software on it comes from Entware project (about 1800 packages).

@zyxmon
Copy link
Author

zyxmon commented Jul 6, 2016

Some more debug output lines

2016-07-06 08:26:33,854 [gdrivefs.gdtool.drive DEBUG] We received (1) changes to apply.
2016-07-06 08:26:33,857 [gdrivefs.gdtool.drive DEBUG] CHANGE: [0B_09GPqvAIMZM1o4a2RLUjd2OGc] [test] (UPDATED)
2016-07-06 08:32:38,893 [gdrivefs.gdfs.fsutility DEBUG] --------------------------------------------------
2016-07-06 08:32:38,904 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>> destroy(24) >>>>>>>>>> (0)
2016-07-06 08:32:38,907 [gdrivefs.gdfs.fsutility DEBUG] DATA: path= [/]
2016-07-06 08:32:38,910 [gdrivefs.gdfs.gdfuse INFO] Stopping change-monitor.
2016-07-06 08:32:42,290 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<< destroy(24) (0)

test is a folder on google drive!

@dsoprea
Copy link
Owner

dsoprea commented Jul 6, 2016

We'll to writes to GD and then rely on the updates coming back from Google
Drive to update the information that we've cached. That's what this section
describes.

This issue is a bit obscure since every single time GDFS emits an IO error
exception, it's preceded by a log-item. I can only assume that the FUSE
library is raising the error, which must mean that one of the calls is
returning data that the FUSE library doesn't like.

My previous comments about how to open it in the foreground not
withstanding, this is the absolute minimum that I see in my log when I
follow the same debug instructions and simply cd in and *cd *out:

### Mount in foreground

vagrant@vagrant-ubuntu-trusty-64:~$ sudo GD_DEBUG=1 GD_MONITOR_CHANGES=0
gdfs /var/cache/gdfs.creds /mnt/g
2016-07-06 06:21:24,635 [gdrivefs.utility INFO] No extension-mapping was
found.
2016-07-06 06:21:24,682 [__main__ DEBUG] Mounting GD with creds at
[/var/cache/gdfs.creds]: /mnt/g
2016-07-06 06:21:24,683 [gdrivefs.gdfs.gdfuse DEBUG] FUSE options:
{}
2016-07-06 06:21:24,684 [gdrivefs.gdfs.gdfuse DEBUG] PERMS: F=777 E=666
NE=444
2016-07-06 06:21:24,686 [gdrivefs.gdtool.drive DEBUG] Getting authorized
HTTP tunnel.
2016-07-06 06:21:24,686 [gdrivefs.gdtool.drive DEBUG] Got authorized tunnel.
FUSE library version: 2.9.2
nullpath_ok: 0
nopath: 0
utime_omit_ok: 0
unique: 1, opcode: INIT (26), nodeid: 0, insize: 56, pid: 0
INIT: 7.22
flags=0x0000f7fb
max_readahead=0x00020000
2016-07-06 06:21:30,207 [gdrivefs.gdfs.fsutility DEBUG]
--------------------------------------------------
2016-07-06 06:21:30,207 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>> init(23)
>>>>>>>>>> (0)
2016-07-06 06:21:30,208 [gdrivefs.gdfs.fsutility DEBUG] DATA: path= [/]
2016-07-06 06:21:30,208 [gdrivefs.gdfs.gdfuse WARNING] We were told not to
monitor changes.
2016-07-06 06:21:30,208 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<< init(23)
(0)
   INIT: 7.19
   flags=0x00000011
   max_readahead=0x00020000
   max_write=0x00020000
   max_background=0
   congestion_threshold=0
   unique: 1, success, outsize: 40

### Do a "cd /mnt/g" from another terminal

unique: 2, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 25393
getattr /
2016-07-06 06:21:53,817 [gdrivefs.gdfs.fsutility DEBUG]
--------------------------------------------------
2016-07-06 06:21:53,817 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>>
getattr(4) >>>>>>>>>> (25393)
2016-07-06 06:21:53,817 [gdrivefs.gdfs.fsutility DEBUG] DATA: fh= [None]
 raw_path= [/]
2016-07-06 06:21:54,036 [gdrivefs.cache.cacheclient_base DEBUG]
CacheClientBase(CacheClientBase,28800)
2016-07-06 06:21:54,037 [gdrivefs.cache.cache_agent INFO] Starting
cache-cleanup thread: <gdrivefs.cache.cache_agent.CacheAgent object at
0x7f3fbd24fc50>
2016-07-06 06:21:54,037 [gdrivefs.gdtool.drive INFO] Getting client for
parent-listing.
2016-07-06 06:21:54,038 [gdrivefs.gdtool.drive INFO] Listing entries over
child with ID [0AJFt2OXeDBqSUk9PVA].
2016-07-06 06:21:54,040 [gdrivefs.cache.cache_agent INFO] Cache-cleanup
thread running: <gdrivefs.cache.cache_agent.CacheAgent object at
0x7f3fbd24fc50>
2016-07-06 06:21:54,982 [gdrivefs.gdtool.drive DEBUG] (1) entries were
retrieved.
2016-07-06 06:21:54,983 [gdrivefs.cache.volume DEBUG] Recursively pruning
entry with ID [0AJFt2OXeDBqSUk9PVA].
2016-07-06 06:21:54,984 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<<
getattr(4) (25393)
   unique: 2, success, outsize: 120
unique: 3, opcode: ACCESS (34), nodeid: 1, insize: 48, pid: 25393
access / 01
   unique: 3, success, outsize: 16

### Do a "cd /" and then unmount (followed by SIGHUP to bring it
completely down, since we're running in the foreground).

unique: 10, opcode: FORGET (2), nodeid: 1, insize: 48, pid: 0
FORGET 1/1
2016-07-06 06:23:18,412 [gdrivefs.gdfs.fsutility DEBUG]
--------------------------------------------------
2016-07-06 06:23:18,412 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>>
destroy(24) >>>>>>>>>> (0)
2016-07-06 06:23:18,412 [gdrivefs.gdfs.fsutility DEBUG] DATA: path= [/]
2016-07-06 06:23:18,412 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<<
destroy(24) (0)

Can you try the same steps?

@zyxmon
Copy link
Author

zyxmon commented Jul 6, 2016

When I cd <mount point> I receive Input/Output Error and no more debug message.
If I mount GD with the mount point as current dir in another console I get

2016-07-06 12:33:43,872 [gdrivefs.gdtool.drive DEBUG] Getting authorized HTTP tunnel.
2016-07-06 12:33:43,875 [gdrivefs.gdtool.drive DEBUG] Got authorized tunnel.
unique: 2, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 23145
getattr /
2016-07-06 12:34:45,091 [gdrivefs.gdfs.fsutility DEBUG] --------------------------------------------------
2016-07-06 12:34:45,093 [gdrivefs.gdfs.fsutility DEBUG] >>>>>>>>>> getattr(4) >>>>>>>>>> (23145)
2016-07-06 12:34:45,097 [gdrivefs.gdfs.fsutility DEBUG] DATA: fh= [None]  raw_path= [/]
2016-07-06 12:34:45,111 [gdrivefs.cache.cacheclient_base DEBUG] CacheClientBase(CacheClientBase,28800)
2016-07-06 12:34:45,115 [gdrivefs.cache.cache_agent INFO] Starting cache-cleanup thread: <gdrivefs.cache.cache_agent.CacheAgent object at 0xc60990>
2016-07-06 12:34:45,122 [gdrivefs.cache.cache_agent INFO] Cache-cleanup thread running: <gdrivefs.cache.cache_agent.CacheAgent object at 0xc60990>
2016-07-06 12:34:45,121 [gdrivefs.gdtool.drive INFO] Getting client for parent-listing.
2016-07-06 12:34:45,127 [gdrivefs.gdtool.drive INFO] Listing entries over child with ID [0AP09GPqvAIMZUk9PVA].
2016-07-06 12:34:46,366 [gdrivefs.gdtool.drive DEBUG] (1) entries were retrieved.
2016-07-06 12:34:46,372 [gdrivefs.cache.volume DEBUG] Recursively pruning entry with ID [0AP09GPqvAIMZUk9PVA].
2016-07-06 12:34:46,387 [gdrivefs.gdfs.fsutility DEBUG] <<<<<<<<<< getattr(4) (23145)
   unique: 2, success, outsize: 120

when I cd ..

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants