NFS mounts do not update after an operation

[toondkn]

This issue occurs when inside NFS mounts (verified) and possibly other async-like filesystems (unverified)

Deleting, renaming, cutting, pasting, ... operations are not visible on folders/files most of the time. Same when adding files by e.g. entering $mkdir dir or $touch file.

The changes do show up sporadically, but this behavior has no apparent consistency and seems to be some kind of race condition.

Adding set period 1 to the lfrc also doesn't make the change show up after 1 second has passed.

Issuing a reload command does make the changes appear.

[gokcehan]

@toonddd We check modification times of directories to trigger load when necessary. Some filesystems do not update these times properly for performance reasons. If so, there is nothing much we can do about it. There might be a related option for updating timestamps when you mount the filesystem.

[toondkn]

~~There is no option to further increase the tightness of the timing mechanism used by NFS.~~ I don't quite understand how NFS handles file attributes. One would assume edits made on the client are reflected immediatly in its filesystem tree. Assumption is the mother of all mistakes though...

ranger and nnn both handle NFS well in this regard.

Is there a way to trigger a load periodically?

[gokcehan]

@toonddd Option period is used to periodically trigger load but load only checks for modification times. There is no option to trigger reload periodically as this would periodically show loading prompts in the screen. You might define custom commands with explicit reload commands as a workaround (e.g. cmd mkdir %mkdir "$@"; lf -remote 'reload'). I don't know how ranger and nnn handle this properly. It might be worth to investigate this further so maybe we can adopt a similar strategy if possible.

[toondkn]

From a (very) cursory glance at ranger's code and based on how it feels in usage, it appears they employ a similar strategy to how the custom command you provided works.

I would love an option to enable a "trigger a reload if an automatic load after the user does something that is expected to result in changes, produces no change" type of behavior.

[gokcehan]

@toonddd Is there a specific place you can link in ranger's code for the mentioned implementation? Shell commands are ubiquitous in lf so it sounds quite wasteful to reload directories after each shell command especially over network file systems. If we could determine somehow whether something would result in changes or not, we could already add the logic to the load command itself. However, we have no semantic knowledge about the shell command that is running. So we can't really have such an option.

I still think the solution for this issue might be related to mount options of the file system. I think it is fair for us to assume if the modification time of the directory is not changed then the directory is the same. Can you give more details about the filesystem and how you mount it on your system? Also can you make sure this is the case, that is modification time of the directory is not changed. For example you can show the output of the following scenario without lf:

[gokcehan@this asd]$ stat .
  File: .
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 801h/2049d	Inode: 588698      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/gokcehan)   Gid: ( 1000/gokcehan)
Access: 2021-02-27 22:07:34.056223298 +0300
Modify: 2021-02-27 22:07:34.056223298 +0300
Change: 2021-02-27 22:07:34.056223298 +0300
 Birth: 2021-02-27 22:07:34.056223298 +0300
[gokcehan@this asd]$ touch foo
[gokcehan@this asd]$ stat .
  File: .
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 801h/2049d	Inode: 588698      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/gokcehan)   Gid: ( 1000/gokcehan)
Access: 2021-02-27 22:07:34.056223298 +0300
Modify: 2021-02-27 22:07:42.685932843 +0300
Change: 2021-02-27 22:07:42.685932843 +0300
 Birth: 2021-02-27 22:07:34.056223298 +0300
[gokcehan@this asd]$ rm foo
[gokcehan@this asd]$ stat .
  File: .
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 801h/2049d	Inode: 588698      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/gokcehan)   Gid: ( 1000/gokcehan)
Access: 2021-02-27 22:07:34.056223298 +0300
Modify: 2021-02-27 22:07:52.335596447 +0300
Change: 2021-02-27 22:07:52.335596447 +0300
 Birth: 2021-02-27 22:07:34.056223298 +0300

[toondkn]

@gokcehan, for ranger: it triggers explicit load_content_if_outdated() calls on every draw of a directory. See https://github.com/ranger/ranger/blob/20cc5e861afbe8c2afed2ce843a1ca6f0bc2f218/ranger/gui/widgets/view_base.py#L33. I couldn't figure out when draws are triggered exactly.

As for the way the filesystem is mounted, these are the parameters:

nfs4 (rw,relatime,vers=4.2,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,timeo=14,retrans=2,sec=sys,clientaddr=SNIP,local_lock=none,addr=SNIP,_netdev)

This is the output of the stat command on file create/remove (format: user@hostname cwd ---$ cmd):

╭toon@m1 ~/SNIP
╰─$ mkdir foo
╭toon@m1 ~/SNIP
╰─$ cd foo
╭toon@m1 ~/SNIP/foo
╰─$ stat .
  File: .
  Size: 0         	Blocks: 0          IO Block: 1048576 directory
Device: 3dh/61d	Inode: 166582      Links: 1
Access: (0755/drwxr-xr-x)  Uid: ( 1000/    toon)   Gid: ( 1000/    toon)
Access: 2021-02-28 17:17:57.922468962 +0100
Modify: 2021-02-28 17:17:57.922468962 +0100
Change: 2021-02-28 17:17:57.922468962 +0100
 Birth: -
╭toon@m1 ~/SNIP/foo
╰─$ touch bar
╭toon@m1 ~/SNIP/foo
╰─$ stat .
  File: .
  Size: 6         	Blocks: 0          IO Block: 1048576 directory
Device: 3dh/61d	Inode: 166582      Links: 1
Access: (0755/drwxr-xr-x)  Uid: ( 1000/    toon)   Gid: ( 1000/    toon)
Access: 2021-02-28 17:17:57.922468962 +0100
Modify: 2021-02-28 17:18:02.732468944 +0100
Change: 2021-02-28 17:18:02.732468944 +0100
 Birth: -
╭toon@m1 ~/SNIP/foo
╰─$ rm bar
╭toon@m1 ~/SNIP/foo
╰─$ stat .
  File: .
  Size: 0         	Blocks: 0          IO Block: 1048576 directory
Device: 3dh/61d	Inode: 166582      Links: 1
Access: (0755/drwxr-xr-x)  Uid: ( 1000/    toon)   Gid: ( 1000/    toon)
Access: 2021-02-28 17:17:57.922468962 +0100
Modify: 2021-02-28 17:18:06.772468930 +0100
Change: 2021-02-28 17:18:06.772468930 +0100
 Birth: -

Seems the modify time gets updated properly.

[gokcehan]

@toonddd Thanks for digging through the code. It seems that ranger uses a similar strategy to use modification times to detect changes. It might be the case that loading is slower on ranger to trigger this issue. Since you mention the behavior is inconsistent, my guess is that there is a delay for updating the modification times. Maybe you could try the following scenario instead to be sure:

[gokcehan@this asd]$ stat .
  File: .
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 801h/2049d	Inode: 580530      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/gokcehan)   Gid: ( 1000/gokcehan)
Access: 2021-03-01 19:48:42.083718610 +0300
Modify: 2021-03-01 19:49:08.193787809 +0300
Change: 2021-03-01 19:49:08.193787809 +0300
 Birth: 2021-03-01 19:48:42.083718610 +0300
[gokcehan@this asd]$ touch foo && stat .
  File: .
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 801h/2049d	Inode: 580530      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/gokcehan)   Gid: ( 1000/gokcehan)
Access: 2021-03-01 19:48:42.083718610 +0300
Modify: 2021-03-01 19:49:17.943812847 +0300
Change: 2021-03-01 19:49:17.943812847 +0300
 Birth: 2021-03-01 19:48:42.083718610 +0300
[gokcehan@this asd]$ stat .
  File: .
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 801h/2049d	Inode: 580530      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/gokcehan)   Gid: ( 1000/gokcehan)
Access: 2021-03-01 19:48:42.083718610 +0300
Modify: 2021-03-01 19:49:17.943812847 +0300
Change: 2021-03-01 19:49:17.943812847 +0300
 Birth: 2021-03-01 19:48:42.083718610 +0300
[gokcehan@this asd]$ rm foo && stat .
  File: .
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 801h/2049d	Inode: 580530      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/gokcehan)   Gid: ( 1000/gokcehan)
Access: 2021-03-01 19:48:42.083718610 +0300
Modify: 2021-03-01 19:49:27.263836399 +0300
Change: 2021-03-01 19:49:27.263836399 +0300
 Birth: 2021-03-01 19:48:42.083718610 +0300
[gokcehan@this asd]$ stat .
  File: .
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 801h/2049d	Inode: 580530      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/gokcehan)   Gid: ( 1000/gokcehan)
Access: 2021-03-01 19:48:42.083718610 +0300
Modify: 2021-03-01 19:49:27.263836399 +0300
Change: 2021-03-01 19:49:27.263836399 +0300
 Birth: 2021-03-01 19:48:42.083718610 +0300

nfs man page mentions a "sync" options. I think it might make modifications appear as they occur. Maybe you can try this option for mounting. You can also try adding sync commands to your commands to see if it makes a difference (e.g. $mkdir foo && sync).

[toondkn]

@gokcehan I tried the exact same scenario yesterday to coax out some async issues, but a stat immediatly after a touch or rm consistently updates the working directory's modification time.

When mounting with the sync option, the problem persists.

Same behavior occurs with sshfs, which works in ranger and nnn as well.

[gokcehan]

@toonddd Alright then I'm marking this as a bug even though I can't reproduce this with sshfs on my setup. Lastly, can you confirm you have the latest version (i.e. r21) and you have this issue without a configuration file using default settings? Also, do you have anything relevant in your log file maybe? If not, I can't really think of anything else at this point and I can't do much without reproducing the error.

[toondkn]

@gokcehan Using version r21, without a configuration file the issue persists. What log file do you want me to check?

[gokcehan]

There are client and server log files in the temporary directory which is deleted on successful exit. You can either watch them from another terminal while the instance is started and still running (e.g. tail -f /tmp/lf.*.log) or display them with keybindings in lf as such:

map ` $less /tmp/lf.${USER}.${id}.log
map ~ $less /tmp/lf.${USER}.server.log

If there is an issue loading directories, there might be an error in log files.

[toondkn]

When creating a folder or touching a file with a shell command issued from within lf, it spits out an error:

2021/03/03 10:43:13 Got EventError: 'read /dev/stdin: resource temporarily unavailable' at 2021-03-03 10:43:13.650119055 +0100 CET m=+8.757188504

This also happens outside nfs mounts, I assume this is normal since the commands don't put anything on stdout.

When removing the touched file or folder I only see the client and server emitting recv and listen logs.

Upon refreshing (ctrl+r), it spits out:

2021/03/03 10:46:14 opening file: open /SNIP: no such file or directory

[allmeta]

Would it be possible to just reload when doing an operation? Like make a macro for copy/pasting buffers in the input config