[389-users] dual change log entry with retro changelog plugin

[Vincent Gerris]

Hi all,

I think I found it, it seems a bug to me.
With audit logging enabled, I noticed a difference in output in the
output log when changing for example a fax field or the password.
I also noticed that this is also reproducible with the 389 admin GUI.
What I see for example with  changing a fax number is:


time: 20130524143610
dn: uid=********,ou=********,o=*********
changetype: modify
replace: telephoneNumber
telephoneNumber: 1234
-
replace: modifiersname
modifiersname: uid=admin,ou=administrators,ou=topologymanagement,o=netscaperoot
-
replace: modifytimestamp
modifytimestamp: 20130524123610Z
-

When ANY modification is made where the password field is modified, I
see something like this:

time: 20130524141847
dn: uid=********,ou=********,o=*********
changetype: modify
delete: preferredLanguage
-
replace: userPassword
userPassword::somelongthingjhere*********************************************************
 =
-
replace: modifiersname
modifiersname: uid=admin,ou=administrators,ou=topologymanagement,o=netscaperoot
-
replace: modifytimestamp
modifytimestamp: 20130524121847Z
-

time: 20130524141847
dn: uid=********,ou=********,o=*********
changetype: modify
replace: passwordgraceusertime
passwordgraceusertime: 0
-

Note the extra time: entry.
Apparently, this extra time enty triggers the creation of the extra
changelog entry.
I looked on the old iPlanet server, when a password is changed there,
there is no second time entry.

Can anyone check this on a recent 389 or RH DS?

kind regards,
Vincent



On Fri, May 24, 2013 at 2:04 PM, Vincent Gerris <vgerris at gmail.com> wrote:
> Hi Ludwig and fellow readers,
>
> I will do that.
> In the mean time I did some more investigating of the access log and
> it seems like a bug to mee.
> It may be true that sometime triggers te bug, but this is what I see
> in the access log:
> [24/May/2013:12:16:48 +0200] conn=20 op=1 MOD
> dn="uid=********,ou=*******,o=*********"
>
> This single MOD log entry in the access log triggers 2 changelog
> entries with the same time step, but one with a higher numer (+1).
> I believe the proper behaviour of the Retro Changelog Plugin schould
> be that only 1 entry is made in the cn-changelog tree.
>
> We are running 9.0.0 of the Red Hat Directory Server now, perhaps this
> is a bug that is fixed in the mean time?
> I am now off to enable Audit logging and perhaps after that look with
> wireshark at what happens.
> I hope in the mean time someone can confirm this bug and maybe a solution?
>
> Thank you.
>
> Kind regards,
> Vincent
>
> On Thu, May 23, 2013 at 3:22 PM, Ludwig Krispenz <lkrispen at redhat.com> wrote:
>>
>> On 05/23/2013 02:22 PM, Vincent Gerris wrote:
>>>
>>> Hi Ludwig,
>>>
>>> We see the same change with a different change number.
>>> This does not happen while using the 389-console or a tool we use to
>>> directly connect to the directory.
>>> When other integration tools are used that do no trigger a duplicate
>>> entry with iPlanet, they do show a duplicate entry.
>>> I can attach a part of the slapd access log file that records this
>>> activity.
>>
>> maybe you can also turn on audit logging and see if there is a difference in
>> the ops from different clients
>>
>>> We are planning a migration from iPlanet 5 to RH DS 9 and this came up
>>> yesterday.
>>>
>>> Kind regards,
>>> Vincent
>>>
>>> On Thu, May 23, 2013 at 9:51 AM, Ludwig Krispenz <lkrispen at redhat.com>
>>> wrote:
>>>>
>>>> What do you mean by two entries - the same change duplicate with
>>>> different
>>>> change numbers or an additional change logged ?
>>>>
>>>> Ludwig
>>>>
>>>>
>>>> On 05/23/2013 08:57 AM, Vincent Gerris wrote:
>>>>>
>>>>> Hi,
>>>>>
>>>>> We are using Red Hat Enterprise Directory Server (which is a stable
>>>>> 389).
>>>>> We have been using the retro changelog plugin from the old iPlanet
>>>>> server for synchronisation to other systems.
>>>>> Yesterday we noticed that for some reason, when an LDAP modification
>>>>> is made, 2 entries turn up in de changelog LDAP tree.
>>>>> It does not seem to happen when the 389-console client is used and a
>>>>> change is made directly to an account with it,
>>>>> but when an LDAP modify is done, while the slapd access logs shows 1
>>>>> modification, the changelog has two entries.
>>>>> This seems to be a bug.
>>>>>
>>>>> Does anyone know how to solve this?
>>>>> I have not found anybody having the issue and nothing in the
>>>>> configuration either.
>>>>> These duplicate entries might result in performance issues on the
>>>>> scripting side.
>>>>> Any help is greatly appreciated!
>>>>>
>>>>> Kind regards,
>>>>> Vincent
>>>>> --
>>>>> 389 users mailing list
>>>>> 389-users at lists.fedoraproject.org
>>>>> https://admin.fedoraproject.org/mailman/listinfo/389-users
>>>>
>>>>
>>>> --
>>>> 389 users mailing list
>>>> 389-users at lists.fedoraproject.org
>>>> https://admin.fedoraproject.org/mailman/listinfo/389-users
>>>
>>> --
>>> 389 users mailing list
>>> 389-users at lists.fedoraproject.org
>>> https://admin.fedoraproject.org/mailman/listinfo/389-users
>>
>>
>> --
>> 389 users mailing list
>> 389-users at lists.fedoraproject.org
>> https://admin.fedoraproject.org/mailman/listinfo/389-users