Use FTL's build-in wait-for command for checking the logs

[yubiuser]

Use pihole-FTL wait-for function to wait for a specific log line to appear.

pi-hole/FTL#2631

[yubiuser]

Tests are failing because the line ########## FTL terminated is not printed anymore. This also happens on bare metal FTL's development branch.
@DL6ER

[DL6ER]

Yes, this is an interesting bug. We free the location where files.log.ftl is stored and thereafter, no new lines are printed to the file. We obviously need an exception here. This is a regression of my recent fixing-all-memory-leaks PR. Seem we want to actually leak at least this single bit of memory.

[DL6ER]

See pi-hole/FTL#2634

[yubiuser]

I tried to use pihole-FTL wait-for also in the tests at

docker-pi-hole/test/tests/test_general.py

Lines 59 to 60 in 5ff925b

	sleep 5
	grep 'terminated' /var/log/pihole/FTL.log

but it did not work. The pihole-FTL wait-for command did not produce any output (which it should even if it did not find the string), I guess it's because start.sh was already killed. It works with the grep version we use so far so I decided not to invest too much time.

[PromoFaux]

but it did not work. ...[snip]... I guess it's because start.sh was already killed.

This is odd to me, too. start.sh shouldn't come into it here? It's not so important, but it is perplexing!!

I'm also wondering if a "better" test for clean shut down is actually volume mounting the logs directory and then checking the contents of the log file after the container has stopped. But that's for another time.

[yubiuser]

I'm also wondering if a "better" test for clean shut down is actually volume mounting the logs directory and then checking the contents of the log file after the container has stopped. But that's for another time.

I think you're onto something here. We should not try to postpone shutdown just to read logs from inside the container.

[yubiuser]

But that's for another time.

#1899

[PromoFaux]

On the PR for the shutdown test - you comment that we check for up to 60 secodns to give slow RISCV devices a chance to start up. Perhaps we should wait 60 seconds here.

[yubiuser]

The difference is: Within the start.sh, pihole-FTL wait-for will only wait for the log line to appear, which is triggered by the capsh --user="${DNSMASQ_USER}" --keep=1 -- -c "/usr/bin/pihole-FTL $FTL_CMD >/dev/null" & line just above. Not much time should be in between.

The other PR watches the container from the outside before it kills the container. There are other (maintenance) tasks before FTL will even be invoked, e.g. running gravity. Therefore I gave it more time.

[casperklein]

FTL's build-in wait-for command uses inotify, which doesn't support network file systems.

https://man7.org/linux/man-pages/man7/inotify.7%40%40man-pages.html

Limitations and caveats
The inotify API provides no information about the user or process
that triggered the inotify event. In particular, there is no easy
way for a process that is monitoring events via inotify to
distinguish events that it triggers itself from those that are
triggered by other processes.
Inotify reports only events that a user-space program triggers
through the filesystem API. As a result, it does not catch remote
events that occur on network filesystems. (Applications must fall
back to polling the filesystem to catch such events.)

This could introduce potential issues with network mounted file systems like NFS/CIFS/SMB.

I found this alternative:

( tail -f -n0 /var/log/pihole/FTL.log & ) | grep -q "########## FTL started"

See also https://superuser.com/a/900134

[PromoFaux]

Just did a simple test from Docker Desktop on windows - though can't guarantee I've done this the right way, it appears to work fine?

[casperklein]

Thanks for testing. I did a bit more research. I think this works, because the changes are made locally by FTL. So the kernel knows about this and inotify works.
It does not work, if the log file is altered by another client or on the server directly where the mount is on.

But that shouldn't be an issue here. Sorry for the noise.

In another project we run into issues, when we watched a certificate file for changes on a NFS mount with inotify. The certificate was managed and renewed externally. Inotify did not work in that case. That triggered me when I saw this PR.

[yubiuser]

@casperklein Thanks for keeping an eye on this. Network share have been causing trouble before already.

[PromoFaux]

No need to apologise for noise!

It's an angle I never thought to test - and I learned something about creating CIFS volumes in docker :)

I tried with an NFS volume too, but there were also all sorts of other permission errors there, with or without this change set. Either I have no idea what I'm doing with NFS, or it is a tricky beast!

Interestingly, I couldn't use a UNC path or a mapped network drive directly in the compose file.