Bug 1257459 - [RFE] Add classification information to error logs and a way to process them in an automated fashion.
[RFE] Add classification information to error logs and a way to process them ...
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: 389-ds-base (Show other bugs)
7.2
All All
unspecified Severity medium
: pre-dev-freeze
: ---
Assigned To: mreynolds
Viktor Ashirov
http://www.port389.org/docs/389ds/des...
: FutureFeature
: 1425881 (view as bug list)
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-08-27 02:30 EDT by Raul Mahiques
Modified: 2017-08-01 17:10 EDT (History)
7 users (show)

See Also:
Fixed In Version: 389-ds-base-1.3.6.1-13.el7
Doc Type: Enhancement
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2017-08-01 17:10:21 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Raul Mahiques 2015-08-27 02:30:01 EDT
Description of problem:
Without having an understanding of what each error message means it is not clear for the common user to understand how critical the issues described are, also this makes it more difficult and time consuming to create scripts to process error logs for purposes such as monitoring.

It will be good if error logs have a severity level assigned to them such as 
syslog(3) error classification scale:

       LOG_EMERG      system is unusable
       LOG_ALERT      action must be taken immediately
       LOG_CRIT       critical conditions
       LOG_ERR        error conditions
       LOG_WARNING    warning conditions
       LOG_NOTICE     normal, but significant, condition
       LOG_INFO       informational message
       LOG_DEBUG      debug-level message

and also if they could be identified by an numeric ID such as:
1234 - the service is shutting down.
4321 - the service is starting up

In this way it would be much easier to automate the processing of the logs to better monitor the status of the service.
This ideally would come with an updated documentation so that normal users can find the meaning of the error without much effort.

Version-Release number of selected component (if applicable):
All versions and releases until now.

How reproducible:
Not relevant.

Steps to Reproduce:
1. Look at the errors log (/var/log/dirsrv/... errors

Actual results:
Error logs are shown as sometimes descriptive strings without clear information about the severity and in multiple lines.

Expected results:
Error logs are shown with an ID and a severity level assigned in a single line together with a short descriptive message
Comment 2 Rich Megginson 2015-08-27 09:30:23 EDT
This is to aid migration from Sun/Oracle DS.  We should see what else Sun/Oracle DS logs to see if there is additional information we can add.

There will need to be a doc component for this - whatever we do in the code, we should do it in such a way that we can generate the docs from the code.

The error code registry should also be in the source code, in a format that can be processed with doxygen.

We will need to make sure that we do not break the console which has an error log parser.
Comment 3 Rich Megginson 2015-08-27 09:32:16 EDT
Upstream ticket:
https://fedorahosted.org/389/ticket/48260
Comment 6 Viktor Ashirov 2017-03-22 12:38:11 EDT
*** Bug 1425881 has been marked as a duplicate of this bug. ***
Comment 8 Viktor Ashirov 2017-04-18 10:52:25 EDT
We have log__error_emergency() that outputs CRITICAL
messages. And LOG_CRIT prints with additional CRITICAL prefix.
I think they should be consistent.
ldap/servers/slapd/log.c
2258:            syslog(LOG_CRIT, "CRITICAL: vslapd_log_emergency_error, Unable to determine system time for message :: %s", msg);
2262:            syslog(LOG_CRIT, "CRITICAL: vslapd_log_emergency_error, Unable to format system time for message :: %s", msg);
2270:            syslog(LOG_CRIT, "CRITICAL: vslapd_log_emergency_error, Unable to format system time for message :: %s", msg);
2335:        log__error_emergency("CRITICAL: vslapd_log_error, Unable to format message", 1 , locked);
2343:            PR_snprintf(buffer, sizeof(buffer), "CRITICAL: vslapd_log_error, Unable to determine system time for message :: %s",
vbuf);
2349:            PR_snprintf(buffer, sizeof(buffer), "CRITICAL: vslapd_log_error, Unable to format system time for message :: %s",
vbuf);
2358:            PR_snprintf(buffer, sizeof(buffer), "CRITICAL: vslapd_log_error, Unable to format system time for message :: %s",
vbuf);
2524:        log__error_emergency("CRITICAL: vslapd_log_access, Unable to format message", 1 ,0);
2533:            PR_snprintf(buffer, sizeof(buffer), "CRITICAL: vslapd_log_access, Unable to determine system time for message :: %s",
vbuf);
2540:            PR_snprintf(buffer, sizeof(buffer), "CRITICAL: vslapd_log_access, Unable to format system time for message :: %s",
vbuf);
2549:            PR_snprintf(buffer, sizeof(buffer), "CRITICAL: vslapd_log_access, Unable to format system time for message :: %s",
vbuf);

ldap/servers/plugins/addn/addn.c
99:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_get_subconfig: CRITICAL: Unable to allocate search_pblock!!!\n");
111:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_get_subconfig: CRITICAL: Internal search pblock get failed!!!\n");
122:        slapi_log_err(SLAPI_LOG_PLUGIN, plugin_name, "addn_get_subconfig: CRITICAL: Internal search error occured %d \n",
search_result);
130:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_get_subconfig: CRITICAL: Unable to retrieve number of entries from
pblock!\n");
144:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_get_subconfig: CRITICAL: Unable to retrieve entries from pblock!\n");
212:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to retrieve plugin configuration!\n");
270:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Failed to validate addn_filter %s for domain %s\n",
config_filter, dn_domain_escaped);
284:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to allocate search_pblock!!!\n");
297:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Internal search pblock get failed!!!\n");
317:        slapi_log_err(SLAPI_LOG_PLUGIN, plugin_name, "addn_prebind: CRITICAL: Internal search error occured %d \n",
search_result);
326:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to retrieve number of entries from pblock!\n");
342:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to retrieve entries from pblock!\n");
359:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to set new mapped DN to pblock!\n");
407:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_start: CRITICAL: Failed to retrieve config entry!\n");
419:                "addn_start: CRITICAL: No default domain in configuration, you must set addn_default_domain!\n");
Comment 9 Amita Sharma 2017-05-03 06:49:19 EDT
I also observed this label is not appropriate -

[03/May/2017:06:42:38.315411654 -0400] - ERR - ldbm_instance_post_delete_instance_entry_callback - Removing 'userRoot'.

This came across while testing - https://bugzilla.redhat.com/show_bug.cgi?id=1391204 and doing 

[0 root@qeos-216 export]# ldapdelete -rx -p 52044 -h localhost -D "cn=Directory Manager" -w Secret123 "cn=userRoot,cn=ldbm database,cn=plugins,cn=config"

It is not an error, just a info?
Comment 10 mreynolds 2017-05-03 09:47:46 EDT
(In reply to Amita Sharma from comment #9)
> I also observed this label is not appropriate -
> 
> [03/May/2017:06:42:38.315411654 -0400] - ERR -
> ldbm_instance_post_delete_instance_entry_callback - Removing 'userRoot'.
> 
> This came across while testing -
> https://bugzilla.redhat.com/show_bug.cgi?id=1391204 and doing 
> 
> [0 root@qeos-216 export]# ldapdelete -rx -p 52044 -h localhost -D
> "cn=Directory Manager" -w Secret123 "cn=userRoot,cn=ldbm
> database,cn=plugins,cn=config"
> 
> It is not an error, just a info?

It's an INFO - I'll change it.
Comment 12 Amita Sharma 2017-06-06 06:56:13 EDT
This is fixed
[05/Jun/2017:08:00:51.593279558 -0400] - INFO - ldbm_instance_post_delete_instance_entry_callback - Removing 'userRoot'.

But issue reported by Viktor in comment#8 did not get fixed.

[root@vm-idm-010 addn]# grep -i "critical" *
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_get_subconfig: CRITICAL: Unable to allocate search_pblock!!!\n");
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_get_subconfig: CRITICAL: Internal search pblock get failed!!!\n");
addn.c:        slapi_log_err(SLAPI_LOG_PLUGIN, plugin_name, "addn_get_subconfig: CRITICAL: Internal search error occured %d \n", search_result);
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_get_subconfig: CRITICAL: Unable to retrieve number of entries from pblock!\n");
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_get_subconfig: CRITICAL: Unable to retrieve entries from pblock!\n");
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to retrieve plugin configuration!\n");
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Failed to validate addn_filter %s for domain %s\n", config_filter, dn_domain_escaped);
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to allocate search_pblock!!!\n");
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Internal search pblock get failed!!!\n");
addn.c:        slapi_log_err(SLAPI_LOG_PLUGIN, plugin_name, "addn_prebind: CRITICAL: Internal search error occured %d \n", search_result);
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to retrieve number of entries from pblock!\n");
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to retrieve entries from pblock!\n");
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_prebind: CRITICAL: Unable to set new mapped DN to pblock!\n");
addn.c:        slapi_log_err(SLAPI_LOG_ERR, plugin_name, "addn_start: CRITICAL: Failed to retrieve config entry!\n");
addn.c:                "addn_start: CRITICAL: No default domain in configuration, you must set addn_default_domain!\n");
==============================

log.c:            syslog(LOG_CRIT, "CRITICAL: vslapd_log_emergency_error, Unable to determine system time for message :: %s", msg);
log.c:            syslog(LOG_CRIT, "CRITICAL: vslapd_log_emergency_error, Unable to format system time for message :: %s", msg);
log.c:            syslog(LOG_CRIT, "CRITICAL: vslapd_log_emergency_error, Unable to format system time for message :: %s", msg);

Hence marking as Assigned.
Comment 13 Amita Sharma 2017-06-12 06:37:36 EDT
Basic functionality is working fine.
Issues logged in above comment can be fixed separately. Hence marking this bug as VERIFIED.
Comment 14 errata-xmlrpc 2017-08-01 17:10:21 EDT
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2017:2086

Note You need to log in before you can comment on or make changes to this bug.