Skip to content

Fix reloading of the configuration from HTTP(S) #2941

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Sep 23, 2024

Conversation

ppkarwasz
Copy link
Contributor

The HttpWatcher didn't propagate the observed last modification time back to the configuration.
As a result, each new Configuration had the same last modification date as the first one and the reconfiguration process looped.

Closes #2937

Copy link
Contributor Author

@ppkarwasz ppkarwasz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In general I took the liberty of bumping some status logger messages to INFO.
IMHO the INFO level should be used for important events like:

  • The start and stop of configurations,
  • The start and stop of logger contexts,
  • Whenever Watcher#isModified returns true, which triggers a reconfiguration.

The overall effect should be the following:

2024-09-10T17:57:04.161594820Z main INFO Starting configuration XmlConfiguration[location=http://localhost:8000/log4j2-file.xml, lastModified=2024-09-10T13:34:24Z]...
2024-09-10T17:57:04.161688451Z main INFO Start watching for changes to http://localhost:8000/log4j2-file.xml every 5 seconds
2024-09-10T17:57:04.162631305Z main INFO Configuration XmlConfiguration[location=http://localhost:8000/log4j2-file.xml, lastModified=2024-09-10T13:34:24Z] started.
2024-09-10T17:57:04.162821558Z main INFO Stopping configuration org.apache.logging.log4j.core.config.DefaultConfiguration@23d2a7e8...
2024-09-10T17:57:04.163001700Z main INFO Configuration org.apache.logging.log4j.core.config.DefaultConfiguration@23d2a7e8 stopped.
2024-09-10T17:57:49.186202317Z Log4j2-TF-2-Scheduled-1 INFO HTTP resource at http://localhost:8000/log4j2-file.xml was modified on 2024-09-10T17:57:44Z
2024-09-10T17:57:49.186810805Z Log4j2-TF-2-Scheduled-1 INFO Configuration source at http://localhost:8000/log4j2-file.xml was modified on 2024-09-10T17:57:44Z, previous modification was on 2024-09-10T13:34:24Z
2024-09-10T17:57:49.191685641Z Log4j2-TF-1-ConfigurationFileWatcher-2 INFO Starting configuration XmlConfiguration[location=http://localhost:8000/log4j2-file.xml, lastModified=2024-09-10T17:57:44Z]...
2024-09-10T17:57:49.191751282Z Log4j2-TF-1-ConfigurationFileWatcher-2 INFO Start watching for changes to http://localhost:8000/log4j2-file.xml every 5 seconds
2024-09-10T17:57:49.191891764Z Log4j2-TF-1-ConfigurationFileWatcher-2 INFO Configuration XmlConfiguration[location=http://localhost:8000/log4j2-file.xml, lastModified=2024-09-10T17:57:44Z] started.
2024-09-10T17:57:49.191969215Z Log4j2-TF-1-ConfigurationFileWatcher-2 INFO Stopping configuration XmlConfiguration[location=http://localhost:8000/log4j2-file.xml, lastModified=2024-09-10T13:34:24Z]...
2024-09-10T17:57:49.192266340Z Log4j2-TF-1-ConfigurationFileWatcher-2 INFO Configuration XmlConfiguration[location=http://localhost:8000/log4j2-file.xml, lastModified=2024-09-10T13:34:24Z] stopped.

@ppkarwasz
Copy link
Contributor Author

Accidentally I had to rewrite HttpThreadContextMapTest. I believe it exploited the fact that its JSON configuration was reloaded every monitor interval. I'll double check that.

Since HttpThreadContextMapTest used Jetty, I rewrote also UrlConfigurationFactoryTest and removed Jetty from the dependencies of log4j-core-test (fixes #2813).

@ppkarwasz ppkarwasz self-assigned this Sep 16, 2024
@ppkarwasz ppkarwasz force-pushed the fix/2.x/2937-http-watcher branch from df6815a to cf73143 Compare September 18, 2024 07:34
@ppkarwasz ppkarwasz changed the base branch from 2.x to 2.24.x September 18, 2024 08:18
@ppkarwasz
Copy link
Contributor Author

@vy, could you take a look at this?

ppkarwasz referenced this pull request Sep 22, 2024
Redirects all `ConfigurationSource` constructors to a single one.
It performs also some null-analysis of the class.
@ppkarwasz
Copy link
Contributor Author

Regarding the Source and ConfigurationSource change I added nullability annotations to both.

ConfigurationSource is basically a triple (Source, byte[] and a long timestamp). The source and data fields can be null, but not at the same time. All the ConfigurationSource#getUri() and similar methods are delegated to Source#getUri(), unless the source field is null.

If we look at the Source class, the uri and location fields can not be null, since each constructor throws something if this happens. The only constructor that does not throw if uri or location are null is the one that takes ConfigurationSource as parameter. I would propose to deprecate that constructor in the next minor release, since it introduces an artificial cyclical dependency between Source and ConfigurationSource.

I have modified the 2 call sites that use the Source(ConfigurationSource) constructor to use more appropriate ones.

Copy link

github-actions bot commented Sep 22, 2024

Job Requested goals Build Tool Version Build Outcome Build Scan®
build-ubuntu-latest clean install 3.9.8 Build Scan NOT_PUBLISHED
Generated by gradle/develocity-actions

@ppkarwasz ppkarwasz force-pushed the fix/2.x/2937-http-watcher branch from aab9235 to 2e4d0a8 Compare September 22, 2024 19:22
@ppkarwasz
Copy link
Contributor Author

While merging #2963, which was based on this PR, I accidentally merged part of these modifications.

It is fixed now, but a force-push was necessary, sorry.

Copy link
Member

@vy vy left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you double-check that I didn't modify the behavior of ConfigurationSource?

New canonical ctor and its usage LGTM, thanks!

I've dropped some more remarks.

The `HttpWatcher` didn't propagate the observed
last modification time back to the configuration.
As a result, each new configuration was already
deprecated when it started and the reconfiguration
process looped.

Closes #2937

Rewrite Jetty tests using WireMock

Closes #2813

Co-authored-by: Volkan Yazıcı <volkan@yazi.ci>
@ppkarwasz ppkarwasz force-pushed the fix/2.x/2937-http-watcher branch from 3598b6a to 211c709 Compare September 23, 2024 20:01
@ppkarwasz ppkarwasz merged commit 211c709 into 2.24.x Sep 23, 2024
3 of 5 checks passed
@ppkarwasz ppkarwasz deleted the fix/2.x/2937-http-watcher branch September 23, 2024 20:02
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Log4j fails to honor lastModifiedTime
3 participants