Error in CI with faas-cli logs

[alexellis]

There's an error that's failing the CI when faas-cli logs is run.

/usr/local/bin/faas-cli logs figlet --since 15m --follow=false | grep Forking
59
Makefile:52: recipe for target 'test-e2e' failed
60
make: *** [test-e2e] Error 1
61
Error: Process completed with exit code 2.

I added a journalctl call to fetch the logs separately, and they are present:

journalctl -t openfaas-fn:figlet --no-pager
45
Journal file /var/log/journal/fdb694e76d02407cbf736a30a801fad9/user-1000.journal is truncated, ignoring file.
46
-- Logs begin at Fri 2021-01-15 16:19:12 UTC, end at Sun 2021-01-17 19:25:41 UTC. --
47
Jan 17 19:25:21 fv-az18-344 openfaas-fn:figlet[11806]: 2021/01/17 19:25:21 Version: 0.13.0        SHA: fa93655d90d1518b04e7cfca7d7548d7d133a34e
48
Jan 17 19:25:21 fv-az18-344 openfaas-fn:figlet[11806]: 2021/01/17 19:25:21 Read/write timeout: 1s, 1s. Port: 8080
49
Jan 17 19:25:21 fv-az18-344 openfaas-fn:figlet[11806]: 2021/01/17 19:25:21 Writing lock-file to: /tmp/.lock
50
Jan 17 19:25:21 fv-az18-344 openfaas-fn:figlet[11806]: 2021/01/17 19:25:21 Metrics server. Port: 8081
51
Jan 17 19:25:26 fv-az18-344 openfaas-fn:figlet[11806]: 2021/01/17 19:25:26 Forking fprocess.
52
Jan 17 19:25:26 fv-az18-344 openfaas-fn:figlet[11806]: 2021/01/17 19:25:26 Wrote 162 Bytes - Duration: 0.001597 seconds

So the issue appears to be related to timing or a race condition. faas-cli logs figlet is not working as expected in CI, but does work when used by end-users in normal use.

[alexellis]

@LucasRoesler when you have a moment, could you a make suggestion or a recommendation for resolution or investigation?

[LucasRoesler]

I created a branch to investigage and the first run passed, but the second run had this interesting bit

$ /usr/local/bin/faas-cli logs figlet --since 15m --follow=false
WARNING! Communication is not secure, please consider using HTTPS. Letsencrypt.org offers free SSL/TLS certificates.
2021-01-17T20:04:54Z 2021/01/17 20:04:54 Version: 0.13.0	SHA: fa93655d90d1518b04e7cfca7d7548d7d133a34e
2021-01-17T20:04:54Z 2021/01/17 20:04:54 Read/write timeout: 1s, 1s. Port: 8080
2021-01-17T20:04:54Z 2021/01/17 20:04:54 Writing lock-file to: /tmp/.lock
2021-01-17T20:04:54Z 2021/01/17 20:04:54 Metrics server. Port: 8081
2021-01-17T20:04:59Z 2021/01/17 20:04:59 Forking fprocess.
2021-01-17T20:04:59Z 2021/01/17 20:04:59 Wrote 162 Bytes - Duration: 0.001486 seconds
2021-01-17T20:05:09Z 2021/01/17 20:05:09 SIGTERM received.. shutting down server in 1s
2021-01-17T20:05:09Z 2021/01/17 20:05:09 Removing lock-file : /tmp/.lock
2021-01-17T20:05:10Z 2021/01/17 20:05:10 No new connections allowed. Exiting in: 1s
$ /usr/local/bin/faas-cli logs figlet --since 15m --follow=false | grep Forking
Makefile:52: recipe for target 'test-e2e' failed
make: *** [test-e2e] Error 1

https://github.com/LucasRoesler/faasd/runs/1717867383?check_suite_focus=true

The take away is that the CLI did get logs the first time but when piped to the grep Forking it failed. I think, that if we want to debug this we need a better test suite, ideally in Go. We can still exec the CLI, but then at least when it fails we can get the actual output it failed on. It is really hard to know if there is something wrong.

[LucasRoesler]

Alternatively, we could use the provider here, since it is testing the same things