Project

General

Profile

Actions

Task #2782

closed

Improve log messages and log levels

Added by Ondrej Husník almost 3 years ago. Updated almost 3 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Ondrej Husník
Target version:
Start date:
04/28/2021
Due date:
% Done:

100%

Estimated time:
Owner:

Description

The goal is to improve log messages in so that them to be more accurate and descriptive.
It's also worth considering revision of used log levels.

Actions #1

Updated by Vladimír Kotýnek almost 3 years ago

Please add user's login to log messages:

28-04-2021 18:12:55,700 DEBUG  SessionId: 2440028477 Calling PasswordFilter - password policy validation
28-04-2021 18:12:55,700 DEBUG  SessionId: 2440028477 Password filter is disabled or not properly configured
...
28-04-2021 18:56:09,704 INFO  SessionId: 2191173396 Some of searched entities are missing in Idm: PASSWORD_FILTER_DEFINITION_NOT_FOUND
28-04-2021 18:56:10,325 WARN  SessionId: 150585112 Idm notify function received http status: 404

In all of these log messages I currently don't know what identity was changing the password. Please extend these messages with login of user to whom the password is changed. The login of the user is the only way to pair validation and notifycation logs for the same user and logs of IdM server (and web server prox).
The old version of password filter library userd to log this way:
Wed Apr 28 18:54:44 2021 loginOFUserOne <Response>true</Response>
Wed Apr 28 18:54:44 2021 loginOFUserOne Finished PasswordFilter()
Wed Apr 28 18:54:44 2021  PasswordChangeNotify()
Wed Apr 28 18:54:44 2021 loginOFUserOne Notify started
Wed Apr 28 18:54:44 2021 loginOFUserOne Finished PasswordFilterNotify()
Wed Apr 28 18:56:09 2021  Entering PasswordFilter()
Wed Apr 28 18:56:09 2021 loginOFUserTwo Started
Wed Apr 28 18:56:09 2021 loginOFUserTwo Config loaded.
Wed Apr 28 18:56:09 2021 loginOFUserTwo Inicializace webove sluzby...
Wed Apr 28 18:56:09 2021 loginOFUserTwo Init SSL hotovo
Wed Apr 28 18:56:09 2021 loginOFUserTwo Nacteno flags: 5 konec flags
Wed Apr 28 18:56:09 2021 loginOFUserTwo ClientContextResponse: 0 konec clientContextResponse
Wed Apr 28 18:56:09 2021 loginOFUserTwo Webova sluzba inicializovana.
Wed Apr 28 18:56:09 2021 loginOFUserTwo zkousim login k IdM...
Wed Apr 28 18:56:09 2021 loginOFUserTwo Response code: 0 konec response
Wed Apr 28 18:56:09 2021 loginOFUserTwo login OK
Wed Apr 28 18:56:09 2021  loginOFUserTwo
Wed Apr 28 18:56:10 2021 loginOFUserTwo <Response>true</Response>
Wed Apr 28 18:56:10 2021 loginOFUserTwo Finished PasswordFilter()
Wed Apr 28 18:56:10 2021  PasswordChangeNotify()
Wed Apr 28 18:56:10 2021 loginOFUserTwo Notify started
Wed Apr 28 18:56:10 2021 loginOFUserTwo Finished PasswordFilterNotify()
Wed Apr 28 19:26:05 2021  Entering PasswordFilter()
Wed Apr 28 19:26:05 2021 loginOFUserThree Started
Wed Apr 28 19:26:05 2021 loginOFUserThree Config loaded.
Wed Apr 28 19:26:05 2021 loginOFUserThree Inicializace webove sluzby...
Wed Apr 28 19:26:05 2021 loginOFUserThree Init SSL hotovo
Wed Apr 28 19:26:05 2021 loginOFUserThree Nacteno flags: 5 konec flags
Wed Apr 28 19:26:05 2021 loginOFUserThree ClientContextResponse: 0 konec clientContextResponse
Wed Apr 28 19:26:05 2021 loginOFUserThree Webova sluzba inicializovana.
Wed Apr 28 19:26:05 2021 loginOFUserThree zkousim login k IdM...
Wed Apr 28 19:26:05 2021 loginOFUserThree Response code: 0 konec response
Wed Apr 28 19:26:05 2021 loginOFUserThree login OK
Wed Apr 28 19:26:05 2021  loginOFUserThree
Wed Apr 28 19:26:06 2021 loginOFUserThree <Response>true</Response>
Wed Apr 28 19:26:06 2021 loginOFUserThree Finished PasswordFilter()
Wed Apr 28 19:26:06 2021  PasswordChangeNotify()
Wed Apr 28 19:26:06 2021 loginOFUserThree Notify started
Wed Apr 28 19:26:06 2021 loginOFUserThree Finished PasswordFilterNotify()

Actions #2

Updated by Ondrej Husník almost 3 years ago

  • Target version set to 1.1.0
Actions #3

Updated by Ondrej Husník almost 3 years ago

  • % Done changed from 0 to 80

Logging messages have been checked. There was added account username to the log in some places as required. The log will look like this one below. At the beginning and the end of the password validation and IdM notification method there are log lines informing about begin/end of the action. These lines also contains user account name. It is introduced by Account: term. Logs in between which often come from called methods do not contain this info. But it is obvious that they pertain to the mentioned account name.
There is also explicitly mentioned the result of the password validation operation.
All logs were also aligned to be better readable.
I also slightly changed log levels. It is recommended to use info log level for general usage.

17-06-2021 14:31:56,396 INFO    SessionId: 2894689538 Account: skippedPrefixFrantaT - Starting password policy validation
17-06-2021 14:31:56,558 INFO    SessionId: 2894689538 Some searched entities are missing in Idm: PASSWORD_FILTER_IDENTITY_NOT_FOUND
17-06-2021 14:31:56,559 INFO    SessionId: 2894689538 Account: skippedPrefixFrantaT - Password policy validation completed with the result: APPROVE
...
17-06-2021 14:31:56,649 INFO    SessionId: 2823076007 Account: skippedPrefixFrantaT - Notifying IdM about password change
17-06-2021 14:31:56,700 WARN    SessionId: 2823076007 Account: skippedPrefixFrantaT - IdM notification response returned with the http status: 404
Actions #4

Updated by Ondrej Husník almost 3 years ago

  • Status changed from New to In Progress
Actions #5

Updated by Ondřej Kopr almost 3 years ago

  • Status changed from In Progress to Resolved
  • % Done changed from 80 to 100

I made review. Padded string with tab is good idea. Whole log file looks better.

Actions #6

Updated by Ondrej Husník almost 3 years ago

  • Status changed from Resolved to Closed
Actions

Also available in: Atom PDF