Reloading is broken in v2.1 with rotate-logs: True

[ulidtko]

As a sidetrack from #294, splitting off a separate issue.

Apparently since #274, app reloading is completely broken, unless rotate-logs has been set to false (i.e. stderr logging). The default for this option when absent in config, is True.

Steps to reproduce

1. In the global keter config, set rotate-logs: True (or omit the option).
2. Have any kind of webapp bundle running as incoming/app.keter.
3. touch incoming/app.keter.

Expected result:

Reload of the app is performed, as if app.keter had changed to a new bundle version.

Actual result:

2024-07-24 19:05:06.41|Keter.AppManager:279|Info> Reloading Just App{appId=dummy} -> AIBundle "/opt/keter/incoming/dummy.keter" 1721847906
2024-07-24 19:05:06.41|Keter.AppManager:285|Error> Error occured when launching bundle "dummy": openFile: resource busy (file is locked)

This file is locked error comes from an attempt to open the (per-app) log-file for the second time for writing. When reloading, it is already open for writing once — by the previous RunningWebApp. Here:

keter/src/Keter/App.hs

Lines 240 to 243 in 6b7f1e4

	case mappLogger of
	Nothing -> withRunInIO $ \rio ->
	bracketOnError (Log.createLoggerViaConfig ascKeterConfig (appLogName aid)) Log.loggerClose (rio . f var)
	Just appLogger -> f var appLogger

(called from reload function in the same module)

---

Does not reproduce on keter 2.0.1 (with the legacy logger, obviously). cc @RiugaBachi @jappeace

I sincerely appreciate the refactoring effort, and the native support for logging to std streams 🚀
However this bug is a showstopper, we can't upgrade our infra to 2.1 due to this.

[jappeace]

we did fix some issue with regards to log rotation:
https://github.com/snoyberg/keter/blob/master/ChangeLog.md#215

[ulidtko]

@jappeace OK, great... but this is different issue.

[RiugaBachi]

Thanks for finding this! I can take a deeper look at this over the weekend.

[m1-s]

I am hitting this as well after updating keter version. Any chance for a fix? Also it appears that by activating rotating logs, its not logging to systemd anymore. Before #274 it was possible to have logging to systemd as well as app specific logs on disk. It would be great to have this behavior restored.

[jappeace]

setting rotate-logs: False will use std err logging, which is captured by systemd (if you launch keter like that).

[m1-s]

Yes but then I am not getting app specific logs on disk anymore. I want both.

[jappeace]

that's a different issue 😅

[ulidtko]

Hi @m1-s, you can probably work out a concoction to get 2 log sinks like that. One arrangement that comes to mind, is keter rotate-logs: False → writes to systemd journald → configure journald with ForwardToSyslog=yes → add syslog.conf with config per your preference to write plaintext logs.

Or perhaps you can habituate to use journalctl directly, it's actually pretty usable IMHO. Has got many integrations with log depots, too... That's beside the point though.

What I wanted to say: you won't get both out of keter alone. If I remember the code correctly, it's an XOR: you either switch rotate-logs: True getting the traditional plaintext files (and, this issue with broken reload!) — or switch rotate-logs: False getting the stdout logging. Not both.

So that I don't come across as condescending: we, too, are stuck with the log/app-foo/current.log approach. Solidly entrenched. So much, that I dread the prospect of changing both the log format, and filepath structure, at once. Thence, our vendor-fork at Zoomin Software hasn't rebased to 2.1 still.