RSS_FUNNEL_WATCH=true is unreliable

[ctechols]

I'm running rss_funnel via a docker compose file with the RSS_FUNNEL_WATCH: true inside the environment: block.

I startup rss_funnel with a valid funnel.yaml file and appropriate RSS_FUNNEL_CONFIG environment setting. The logs report:

rssfunnel-1  | 2024-03-12T14:35:04.534164Z  INFO rss_funnel::server: watching config file for changes
...<snipped for brevity>...
rssfunnel-1  | 2024-03-12T14:35:04.674727Z  INFO rss_funnel::server: starting server

Then I edit my funnel.yaml to completely remove one of the endpoints. The logs then report:

rssfunnel-1  | 2024-03-12T14:42:14.539908Z  INFO rss_funnel::server: config updated, reloading service

After that I go to my browser, reload the inspector page and also click the "Reload Config" button. I would expect the endpoint I just deleted to be absent from the inspector UI, but it is still present.

I can mostly get the logs to report a successful reload if I change a config from invalid to valid. However even then it doesn't appear to always work. (Sorry I don't have more concrete reproduction steps).

[shouya]

That is weird. I attempted to reproduce it without success. I tried adding and removing endpoints, each of the change is successfully picked up by the file system watcher and the ui after pressing the "Reload Config" button.

I'm suspecting maybe it's the inotify event are not passing through docker mount boundary. On my development environment I run the binary directly without docker, and in my docker deployed node I don't use the watch feature.

Can you give me your docker-compose.yaml? I'll see if I can reproduce it with the exact config.

[ctechols]

This minimal docker-compose.yml reproduces the issue for me:

version: '3.7'

services:
  rssfunnel:
    image: "ghcr.io/shouya/rss-funnel:0.1.0"
    restart: unless-stopped
    volumes:
      - ./funnel.yaml:/funnel.yaml
    ports:
      - 4081:4081
    environment:
      RSS_FUNNEL_CONFIG: /funnel.yaml
      RSS_FUNNEL_BIND: 0.0.0.0:4081
      RSS_FUNNEL_WATCH: true

[ctechols]

I decided to test the non-docker, linux x86 released version from here: https://github.com/shouya/rss-funnel/releases/tag/0.1.0

I started rss-funnel with the following command:

12:45:25 fs:~/docker-services/rss-funnel-repro %> ./rss-funnel --config ./funnel.yaml server --bind 0.0.0.0:4081 -w

It started successfully and I loaded the inspector UI successfully. Then I removed an endpoint from funnel.yaml. The log message printed as expected:

2024-03-12T16:46:25.343738Z  INFO rss_funnel::server: config updated, reloading service

I then reloaded the inspector UI, and the deleted endpoint was removed from the inspector.

However, I then restored the deleted endpoint to funnel.yaml and saved the file. The log did not print the reloading message and the restored endpoint would not show up in the inspector UI after reloading.

[shouya]

Unfortunately, I was unable to reproduce the issue with either docker-compose or the downloaded binary (x86_64-unknown-linux-musl).

I noticed a potential issue in your docker-compose.yml file. The line RSS_FUNNEL_WATCH: true is invalid because true is interpreted as a boolean in YAML, whereas it expects environment values to be strings. The correct usage would be RSS_FUNNEL_WATCH: "true" (with quotes around "true"). However, this couldn't be the cause of the issue you're facing because if the boolean value is not parsed correctly, the app wouldn't even start, and you wouldn't see the "watching config file for changes" output.

I tried running both the debug and release builds on the master branch and the 0.1.0 tag, and all attempts exhibited the desired behavior. I also attempted to build a Docker image under the identical settings used for building 0.1.0, and it worked fine.

My current best guess is that the issue may be related to the difference between our operating systems. Could you please let me know which operating system you're running (both the host and the os the docker-machine runs on)? For reference, I'm using Debian Linux.

[ctechols]

I am also using debian linux:

09:04:47 fs:~ %> uname -a
Linux fs 6.1.0-18-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.76-1 (2024-02-01) x86_64 GNU/Linux

The issue seems to be with vim and how its method for saving files interacts with inotify on linux. The specific option in question is backupcopy. Its default value is 'auto' on unix when not in vi-compatible mode. This gives vim the permission to rename the original file to a backup file and then write the edited contents as a new file with the original name. This behavior leads to inotify monitoring the backup file instead of the original file.

To avoid breaking the inotify monitor, backupcopy must be set to 'yes'.

I diagnosed this by running inotifywait -m funnel.yaml and them comparing the output when editing the file with vim vs editing the file with nano. That led me down a rabbit hole where I found this stackoverflow post

There's some discussion of using inotify to monitor the parent directory of the target file. Then inotify would fire events for renames within that directory. This would come at the cost of using more resources. The max number of inotify watches is limited by system configuration.

This is all just for your information. Feel free to close this issue if you think it's out of scope for rss-funnel.

[shouya]

Thanks for that valuable info, it makes total sense. If the issue is really caused by Vim's backupcopy mechanism, then I could probably capture that by triggering a reload not just on the file modification event, but also on other related inotify events for that single file. I'll test that out to see if it solves the problem. But if I have to listen to the whole directory to reliably catch the event, then as you mentioned, it may not be worth pursuing further due to the potential performance implications.

[ctechols]

Further testing with inotifywait makes me think you could get away with watching only the parent directory of funnel.yaml. That would be more total events to filter through, but you'd only be watching a single inode and not consuming more of a capped system resource.

I tested running inotifywait -m . (notice the absence of the -r flag, so it's not recursive) in the directory that contains funnel.yaml, and then editing the file with both nano and vim with the default backupcopy value. If you filter on CLOSE events and the funnel.yaml filename, you might get all the events you need to reliably reload the config.

When testing the above, I used this script to query the number of inotify watches that are in use and it reports only 1 for the inotifywait process.

[shouya]

@ctechols: Thank you for the bug report and extremely helpful investigation. The issue you identified has been resolved in pull request #84. You can expect the upcoming release to include this fix.

[ctechols]

@shouya I tested release 0.1.2 this morning. The binary release has indeed fixed the issue with vim. Unfortunately, the docker image is not working. It's displaying the same behavior in the initial bug report.

I've not tested this theory at all, but I have a suspicion vim's backupcopy behavior has issues with docker bind mounts similar to the issues rss-funnel was having.

I've added an entry to the FAQ that explains the issue and suggests a minimal workaround.

[shouya]

Thank you for updating the doc.

The reload is not supposed to work with Docker. On file save, the bind mounted file is simply removed from Docker's point of view. Although I didn't confirm this, but I don't think Docker is going to rebind the file under the same name. So the program is just unable to see the new file inside Docker.