I just installed FreeIPA from master branch bits, and run the test suite. This resulted in many dirsrv errors logs which may or may not be benign (and was not there before):
[28/Feb/2014:10:42:33 +0100] - Listening on All Interfaces port 636 for LDAPS requests [28/Feb/2014:10:42:33 +0100] - Listening on /var/run/slapd-IDM-LAB-ENG-BRQ-REDHAT-COM.socket for LDAPI requests [28/Feb/2014:10:43:03 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:10:49:59 +0100] - Operation error fetching Null DN (9f85de14-a05d11e3-9fe5a234-9957fd81), error -30993. [28/Feb/2014:10:49:59 +0100] - Operation error fetching Null DN (9f85de15-a05d11e3-9fe5a234-9957fd81), error -30993. [28/Feb/2014:10:49:59 +0100] - Operation error fetching Null DN (9f85de16-a05d11e3-9fe5a234-9957fd81), error -30993. [28/Feb/2014:10:50:00 +0100] - Operation error fetching Null DN (9f85de17-a05d11e3-9fe5a234-9957fd81), error -30993. [28/Feb/2014:13:06:37 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:13:06:40 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:13:06:43 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:13:07:03 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:13:07:12 +0100] - Entry "cn=ipaConfig,cn=etc,dc=example,dc=com" -- attribute "invalid_attr" not allowed [28/Feb/2014:13:07:16 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 ... [28/Feb/2014:13:12:47 +0100] - Operation error fetching Null DN (9999f846-a07111e3-9fe5a234-9957fd81), error -30993. [28/Feb/2014:13:12:48 +0100] - Operation error fetching Null DN (9999f847-a07111e3-9fe5a234-9957fd81), error -30993. [28/Feb/2014:13:13:03 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:13:13:04 +0100] ipa_range_check_pre_op - [file ipa_range_check.c, line 307]: Missing entry to modify. ... [28/Feb/2014:13:28:17 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:13:28:55 +0100] NSACLPlugin - ACL Invalid Target Error(-8): Target is beyond the scope of the ACL(SCOPE:cn=etc,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com) (targetattr = \22sn\22)(target = \22ldap:///uid=admin,cn=users,cn=accounts,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com\22)(version 3.0;acl \22permission:testperm\22;allow (write) groupdn = \22ldap:///cn=testperm,cn=permissions,cn=pbac,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com\22;) [28/Feb/2014:13:29:32 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 ... [28/Feb/2014:13:40:37 +0100] - str2entry_dupcheck: Duplicate value for attribute type sudoRunAsGroup detected in entry cn=testing_sudorule1,ou=sudoers,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com. Extra value ignored. [28/Feb/2014:13:40:42 +0100] - str2entry_dupcheck: Duplicate value for attribute type sudoRunAsGroup detected in entry cn=testing_sudorule1,ou=sudoers,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com. Extra value ignored. [28/Feb/2014:13:40:44 +0100] - str2entry_dupcheck: Duplicate value for attribute type sudoRunAsGroup detected in entry cn=testing_sudorule1,ou=sudoers,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com. Extra value ignored. [28/Feb/2014:13:40:45 +0100] - str2entry_dupcheck: Duplicate value for attribute type sudoRunAsGroup detected in entry cn=testing_sudorule1,ou=sudoers,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com. Extra value ignored. [28/Feb/2014:13:40:54 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 ... [28/Feb/2014:13:42:47 +0100] - Operation error fetching Null DN (ca7c2c27-a07511e3-9fe5a234-9957fd81), error -30993. [28/Feb/2014:13:44:41 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:13:44:41 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1 [28/Feb/2014:13:44:44 +0100] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code -1
If you say "was not there before" can you tell with which version the messages started ?
There are several different error messages: SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN Operation error str2entry_dupcheck: ....
are they all new ?
I am not entirely sure, not all may be new. But there is too many of such errors and it makes me thinking there may be errors in our DS plugins for or even DS itself - this is something we need to check.
I'm new to ipa testing, which tests did you run: in-tree or integration, a specific test suite ?
ok, I did run the in-tree tests and did see these error messages, starting investigation
Good! Thanks.
I investigated the first set of errors: SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN
Looks like they are triggered by usn_bepostop_delete when trying to delete a nonexisting entry. The backend is NULL and since a commit in jul/13 the plugin returns -1 if the backend is NULL.
IMO this looks like something we should fix as for example a misbehaving clients trying often to delete a non-existent entry could quickly fill the logs with garbage.
Replying to [comment:8 mkosek]:
yes. I wanted to investigate the other error messages and then create tickets for 389
The "Operation error" message is related to the way we handle locks in BDB, it is thrown if a lock isn't granted immediately and there will be a retry. Not sure why it shows up now.
Ok, thanks. BTW please post the ticket URLs to this ticket as well, just for maintaining the reference.
Only CC'ing myself to stay informed as I also see the following on my F20 FreeIPA instances as well.
[06/Mar/2014:07:54:39 -0600] - Operation error fetching Null DN (cd27c704-a53611e3-af64ece9-0f614971), error -30993. [06/Mar/2014:12:59:59 -0600] - Operation error fetching Null DN (68ce2d03-a56111e3-af64ece9-0f614971), error -30993.
Here is my summary on the error messages generated in IPA tests
1] SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN messages. This is caused by an incorrect return code of the usn plugin if an attempt is made to delete an non existing entry. It is handled in 389 as ticket: https://fedorahosted.org/389/ticket/47732 I have tested a fix, needs to be reviewed
2]Operation error fetching Null DN messages I do not understand yet why these messages are logged and if they can be ignored/suppressed/avoided. I did see them in the ipa test run on F20, not on F19. When testing my fix for 1] based on current master on F19 I didn't see these messages though, but since the messages are database locking related it can also be a timing issue. I created ticket: https://fedorahosted.org/389/ticket/47733 Needs further investigation.
3] "ipa_range_check_pre_op", "invalid_attr" and "unknown object class ipapermissionv2" messages I think these are valid messages for specific testcases intended to fail
4] "str2entry_dupcheck: Duplicate value for attribute type sudoRunAsGroup" and "NSACLPlugin - ACL Invalid Target Error(-8): Target is beyond.."
I didn't see these messages in the in-tree tests. How can they be triggered ?
ds389 tickets 47732 and 47733 are fixed now
Moving stabilization tickets that do not affect FreeIPA 4.0 release usability in any significant way to 4.0.1 stabilization milestone.
When running the DS tests on the latest DS F20 release (389-ds-base-1.3.2.20-1.fc20.x86_64), I did not spot the before mentioned errors. The DS fixes mentioned in comment:15 did the job right.
Closing the ticket as resolved, thanks!
Metadata Update from @mkosek: - Issue assigned to lkrispen - Issue set to the milestone: FreeIPA 4.0.1
Login to comment on this ticket.