Project

General

Profile

Actions

Task #3036

closed

Upgrade logback to 1.2.10

Added by Peter Štrunc over 2 years ago. Updated about 2 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Peter Štrunc
Category:
Logging
Target version:
Start date:
01/14/2022
Due date:
% Done:

100%

Estimated time:
Owner:

Description

In response to recently found vulnerabilities: https://logback.qos.ch/news.html


Related issues

Related to IdStory Identity Manager - Task #3101: Logging events are generated with low IDs, possible collisionNewRoman Kučera04/07/2022

Actions
Actions #1

Updated by Peter Štrunc about 2 years ago

  • Status changed from New to In Progress
  • % Done changed from 0 to 60

There have been multiple issues with this seemingly straightforward upgrade.

I had to add another clause to "dependencyManagement" section in pom.xml in the parent project, where we manually override logback-core and logback-classic. This, after many other tries, seems to be working well and dependency-list no more shows version 1.2.3.

The issue, which arises from upgrading to version 1.2.9+ is that logback developers decided to patch the vulnerability by completely removing all of the database code. This means, that after the upgrade, a feature of logging into the database stops working and we needed to find another way to re-enable it.

We came up with an idea to use our existing services, which we use to read logback tables, to also write data to the mentioned tables. However this looks promising, it comes with a caveat - we are no longer able to log anything, that happens before ApplicationContext initialization, to the database. This from now becomes a known issue, which we may, or may not solve in the future (after we consulted it internally, it is likely that it will stay that way). There is a somewhat plausible solution, which involves adding https://github.com/qos-ch/logback-extensions to CzechIdM and using DelegatingLogbackAppender to wrap our own appender.

I managed to make this work and successfully tested, that it logs all levels of logs.

Implementation can be found in pstrunc/upgrade-logback but it needs some cleaning still.

What we also want, is to have a separate connection pool for this database logging. The point is to not hog application database connections when logging goes awry. I have prepared a solution to this locally, but still need to test it thoroughly, because I found some info about spring having issues with instantiating multiple connection pools (https://stackoverflow.com/questions/45876443/how-to-setup-multiple-connection-pools-when-multiple-datasources-are-used-in-spr)

Also tests and doc is needed

Actions #2

Updated by Peter Štrunc about 2 years ago

  • % Done changed from 60 to 70

I managed to configure two Hikari datasources, but there is still an issue with envers and auditing. The problem seems to be related to this:

https://stackoverflow.com/questions/56950660/envers-queries-use-wrong-column-names-for-mod-columns

but with the original configuration, this does not occur. It looks like Spring Boot Datasource autoconfiguration (which is now newly disabled) did some magic, that prevented this from happening. Sadly I am yet to find, what the magic was. I tried to set a different naming strategy, but it had no noticeable effect. If I turn off property spring.jpa.properties.org.hibernate.envers.global_with_modified_flag, then everything works (except for auditing changes, which this property enables).

There is still some work to be done on this. I hope I will crack it tomorrow.

Side note: I managed to solve an issue with multiple entity managers and annotation @Primary not working, but it involves specifying @Qualifier annotation on every place, where we try to autowire EntityManager. This will need to be checked when upgrading on projects.

Actions #3

Updated by Peter Štrunc about 2 years ago

  • % Done changed from 70 to 80

We decided, that we are going to postpone the functionality of having multiple datasources to version 12.2.0 since it is such a big change. Work will continue in ticket #3052

Actions #4

Updated by Peter Štrunc about 2 years ago

  • Status changed from In Progress to Needs feedback
  • Assignee changed from Peter Štrunc to Tomáš Doischer

I added Javadoc and test. Would you please review this @doischert?

Actions #5

Updated by Tomáš Doischer about 2 years ago

  • Assignee changed from Tomáš Doischer to Peter Štrunc

Thank you, I have done code review and tested logging. Logging works, great job!

Notes:
  • I have some errors in log during logging:
    2022-02-10 08:33:23.752  WARN 202875 --- [AsyncAppender-Worker-DB_ASYNC] org.hibernate.engine.jdbc.spi.SqlExceptionHelper.logExceptions : SQL Error: 0, SQLState: 23502
    2022-02-10 08:33:23.753 ERROR 202876 --- [AsyncAppender-Worker-DB_ASYNC] org.hibernate.engine.jdbc.spi.SqlExceptionHelper.logExceptions : ERROR: null value in column "i" violates not-null constraint
      Detail: Failing row contains (34240, null, eu.bcvsolutions.idm.core.api.exception.ResultCodeException: Iden...).
    
Not quite sure why this is, perhaps we can look at it together. This happened once when activating an active user.
  • unused imports in: DefaultIdmLoggingEventService, DefaultIdmLoggingEventExceptionService, IdmLoggingEventExceptionPrimaryKey, IdmDbAppender, IdmDbAppenderTest, DefaultEntityEventManager, EntityEventLockQueueMonitoringEvaluator, LongRunningTaskResultMonitoringEvaluator (even unused Autowired service) - some of these are not from this feature but I think it is new code (I think IntelliJ IDEA does not report this by default)
  • please update the changelog
Actions #6

Updated by Peter Štrunc about 2 years ago

  • Assignee changed from Peter Štrunc to Tomáš Doischer
  • % Done changed from 80 to 90

Thanks for the review @doischert I fixed all the issues. Pull request is here https://github.com/bcvsolutions/CzechIdMng/pull/170. If you find no other issues, please merge it. Thanks :)

Actions #7

Updated by Peter Štrunc about 2 years ago

I will update changelog directly in develop

Actions #8

Updated by Tomáš Doischer about 2 years ago

  • Status changed from Needs feedback to Resolved
  • Assignee changed from Tomáš Doischer to Peter Štrunc
  • % Done changed from 90 to 100

LGTM, thank you! Merged to develop.

Actions #9

Updated by Peter Štrunc about 2 years ago

  • Status changed from Resolved to Closed
Actions #10

Updated by Alena Peterová about 2 years ago

  • Related to Task #3101: Logging events are generated with low IDs, possible collision added
Actions

Also available in: Atom PDF