Big news! The community will be moving to a new platform April 21. Read more.
Big news! The community will be moving to a new platform April 21. Read more.
Commander
Commander
2826 views

Discarding transaction because entry was deleted

Hi All,

I have an issue with the Google Apps driver. Here is the entirety of the level 3 trace when I try to migrate an account using iManager and the Google Apps driver.

[09/07/18 09:47:09.218]:IDM4GMAIL ST:Start transaction.
[09/07/18 09:47:09.218]:IDM4GMAIL ST:Discarding transaction because entry was deleted.


The association state on the user object changes to Migrate from Processed.

If I delete the association from the user account, I can migrate the account successfully and a match is found. Any subsequent migrate results in the condition above. This is happening to multiple user objects.

Google driver is version 4.1.1.5.

Any advice appreciated.

Thanks
Adam
Labels (1)
0 Likes
28 Replies
Knowledge Partner Knowledge Partner
Knowledge Partner

keil0008;2487375 wrote:
Apologies for the delayed response. I have enabled a level 10 trace as seen below. Note, the same config is running in our UAT environment with no problems.


[09/11/18 15:40:13.859]:IDM4GMAIL :Trace Level changed to 10
[09/11/18 15:40:33.400]:IDM4GMAIL ST:Start transaction.
[09/11/18 15:40:33.400]:IDM4GMAIL ST:type(resync-entry)entry-id(4) dn(null) class-id(-1) class-name(null)
[09/11/18 15:40:33.400]:IDM4GMAIL ST:Discarding transaction because entry was deleted.


EDIT: Obviously the curiosity is that the dn=null. Any idea what would cause this?


That doesn't look to me like a Google driver bug. That looks like the engine can't find the object that clearly it should be able to find if you're migrating it.

Possibly driver rights to objects is wrong? If not already, make the driver security equal to "admin" so it has all rights and re-test.

If that's not it, I think you'll need an SR to work with support on figuring out what's going on here.
0 Likes
Knowledge Partner Knowledge Partner
Knowledge Partner


>>>

> Code:
> --------------------
> > >

> > [09/11/18 15:40:13.859]:IDM4GMAIL :Trace Level changed to 10
> > [09/11/18 15:40:33.400]:IDM4GMAIL ST:Start transaction.
> > [09/11/18 15:40:33.400]:IDM4GMAIL ST:type(resync-entry)entry-id(4) dn(null) class-id(-1) class-name(null)
> > [09/11/18 15:40:33.400]:IDM4GMAIL ST:Discarding transaction because entry was deleted.
> >

> --------------------
>>>

>>
>> EDIT: Obviously the curiosity is that the dn=null. Any idea what would
>> cause this?


That DN=null is interesting. I would stop the driver, generate the
resync event and then using either iManager or dxcmd look at the event
in the queue. It will be XML XDS so paste that in here... Maybe that
is really the issue?

> That doesn't look to me like a Google driver bug. That looks like the
> engine can't find the object that clearly it should be able to find if
> you're migrating it.


Agreed.

> Possibly driver rights to objects is wrong? If not already, make the
> driver security equal to "admin" so it has all rights and re-test.


I think you would be seeing a 672 in trace error if missing permissions.

Is it possible the server does not have a replica of this object? I.e.
Driverset is on multiple servers, and generating on serverA with
replica, but this driver is running on ServerB missing a replica.


> If that's not it, I think you'll need an SR to work with support on
> figuring out what's going on here.
>
>


0 Likes
Knowledge Partner Knowledge Partner
Knowledge Partner

Agree with David!
Like I mentioned early, this issue "on Subscriber channel" (engine side) and you have to see similar issues on all your drivers.

You can create simple Loopback driver (or any another driver) and repeat your steps.
I expect to see similar issue.
0 Likes
Commander
Commander

Thanks for the helpful suggestions. Still having a problem. The driver is running as the admin user.

I stopped the driver and tried a migrate as per geoffc's suggestion. Inspecting the cache you can see the sync event without any data.



I attempted the same on a different driver and indeed that produced the same result.


NOTE: Don't be confused by the filename of AD_Loopback. That was just a file naming mistake.

If I delete the association however, the object is added correctly to the cache.



I think I'll have to raise an SR now as it's shown to affect more than just the Google Driver.
0 Likes
Knowledge Partner Knowledge Partner
Knowledge Partner

On 9/12/2018 7:54 PM, keil0008 wrote:
>
> Thanks for the helpful suggestions. Still having a problem. The driver
> is running as the admin user.
>
> I stopped the driver and tried a migrate as per geoffc's suggestion.
> Inspecting the cache you can see the sync event without any data.
>
> [image: https://image.ibb.co/kZ7Sh9/Failed_with_association_Gmail.png]
>
> I attempted the same on a different driver and indeed that produced the
> same result.
>
> [image: https://image.ibb.co/kvjb9p/AD_Loopback.png]
> NOTE: Don't be confused by the filename of AD_Loopback. That was just a
> file naming mistake.
>
> If I delete the association however, the object is added correctly to
> the cache.
>
> [image: https://image.ibb.co/eY1nh9/Success_with_no_Association.png]
>
> I think I'll have to raise an SR now as it's shown to affect more than
> just the Google Driver.


The first two are not correct at all. No info, so no reference to the
object, so the engine discards it, since it cannot find the object.

So the real question is why does no Associatin work, with an association
does not work.


0 Likes
Commander
Commander

Bit more info. Browsing to the user object and querying the target for values is successful. This is after a failed migrate and the driver reporting the event was discarded because entry was deleted.

0 Likes
Knowledge Partner Knowledge Partner
Knowledge Partner

On 9/13/2018 2:34 AM, keil0008 wrote:
>
> Bit more info. Browsing to the user object and querying the target for
> values is successful. This is after a failed migrate and the driver
> reporting the event was discarded because entry was deleted.
>
> [image: https://image.ibb.co/fsxzVU/query.png]


The issue was shown when you had a <sync/> event in the queue. That is
invalid (no @src-dn) and thus the error you see is not an error, it is
correct.

How you got that event into the queue is the error.


0 Likes
Knowledge Partner Knowledge Partner
Knowledge Partner

keil0008;2487504 wrote:
Thanks for the helpful suggestions. Still having a problem. The driver is running as the admin user.

I stopped the driver and tried a migrate as per geoffc's suggestion. Inspecting the cache you can see the sync event without any data.



I attempted the same on a different driver and indeed that produced the same result.


NOTE: Don't be confused by the filename of AD_Loopback. That was just a file naming mistake.

If I delete the association however, the object is added correctly to the cache.



I think I'll have to raise an SR now as it's shown to affect more than just the Google Driver.


That's very wrong. Yes, I think it's SR time on this one. You have something very strange going on there.

Please let us know what it was when you get it figured out.
0 Likes
Commander
Commander

I will raise an SR I think. FYI. I stopped the Google Apps driver on IDVPRD01 and started it on IDVPRD02 and migrating a user (one that had previously failed) works fine. So it points to an issue with the server IDVPRD01.

I ran a dsrepair -R yesterday and it didn't make any difference. Shifting the driver to a new server does resolve the issue. I will keep troubleshooting IDVPRD01.

I enabled dstrace yesterday to see if I could see anything.

I did observe some of these errors but they seem unrelated:
09:48:00 40F1C700 Agent: WPutEntryAttrs failed, insufficient buffer (-649)


It also appears that maybe the server object itself was trying to read the user object and failing. I would have thought it should be being read by the user the driver is confifgured to run as?

DXML Trace (for time ref):
[09/14/18 10:13:25.989]:IDM4AD ST:Start transaction.
[09/14/18 10:13:25.989]:IDM4AD ST:Discarding transaction because entry was deleted.


DSTRACE:

10:13:25 63658700 Agent: Calling DSARead conn:0 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:13:25 63052700 Agent: Calling DSARead conn:0 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:13:25 64675700 Agent: Calling DSARead conn:0 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:13:25 64675700 Agent: Calling DSAGetEffectiveRights conn:0 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:13:25 64675700 Agent: Calling DSAResolveName conn:32 for client .[Public].
10:13:25 64675700 Agent: Calling DSAReadObjectInfo conn:32 for client .[Public].
10:13:25 62A4C700 Agent: Calling DSAReadObjectInfo conn:0 for client .IDVPRD01.RESOURCES.UOFAIDV.
09/14/18
10:13:25 62A4C700 Agent: DSAReadObjectInfo failed, no such entry (-601).
10:13:25 62A4C700 Agent: Calling DSARead conn:0 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:13:25 62A4C700 Agent: DSARead failed, no such entry (-601).
10:13:25 64675700 Agent: Calling DSAReadObjectInfo conn:0 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:13:25 63658700 Agent: Calling DSARead conn:0 for client .IDVPRD01.RESOURCES.UOFAIDV.
0 Likes
Commander
Commander

FYI: Here is the DSTRACE from IDVPRD02 when the migrate operation succeeds. It appears to read the object from IDVPRD01.

The test user involved is a1999973.PEPOLE.UOFAIDV

10:23:16 91F46700 Agent: Calling DSAResolveName conn:18 for client .[Public].
10:23:16 BCD17700 Agent: Calling DSAStartUpdateReplica conn:16 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:23:16 BCD17700 SyncI: Start inbound sync from server [000080a7] <.IDVPRD01.RESOURCES.UOFAIDV.> for partition [000080b2] <.PEOPLE.UOFAIDV.>.
10:23:16 BCE18700 Agent: Calling DSAUpdateReplica conn:16 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:23:16 BCE18700 SyncI: *Received packet with entry count 2 from [000080a7] <.IDVPRD01.RESOURCES.UOFAIDV.>
09/14/2018
10:23:16 BCE18700 SyncI: **Processing incoming value for attribute .Transitive Vector.[Attribute Definitions].[Schema Root].
10:23:16 BCE18700 SyncI: *.IDVPRD01.RESOURCES.UOFAIDV. updated [000080b2] <.PEOPLE.UOFAIDV.>
10:23:16 BCE18700 SyncI: *Finished applying changes to [000080b2] <.PEOPLE.UOFAIDV.>, succeeded 2005/12/16 13:06:26, 1, 1
10:23:16 BCE18700 SyncI: **Processing incoming value for attribute .Revision.[Attribute Definitions].[Schema Root].
10:23:16 BCE18700 SyncI: **Processing incoming value for attribute .DirXML-Associations.[Attribute Definitions].[Schema Root].
10:23:16 BCE18700 SyncI: **Processing incoming value for attribute .modifiersName.[Attribute Definitions].[Schema Root].
10:23:16 BCE18700 SyncI: *.IDVPRD01.RESOURCES.UOFAIDV. updated [0002d94f] <.a1999973.PEOPLE.UOFAIDV.>
10:23:16 BCE18700 SyncI: *Finished applying changes to [0002d94f] <.a1999973.PEOPLE.UOFAIDV.>, succeeded 2018/03/22 13:38:59, 3, 2
10:23:16 BBD07700 Agent: Calling DSAEndUpdateReplica conn:16 for client .IDVPRD01.RESOURCES.UOFAIDV.
10:23:16 BBD07700 SyncI: Merge Transitive Vectors, succeeded for .PEOPLE.UOFAIDV.
10:23:16 BBD07700 SyncI: Partition .PEOPLE.UOFAIDV.: Updating local Transitive Vector, succeeded
10:23:16 BBD07700 SyncI: Objects received: 2, from server <.IDVPRD01.RESOURCES.UOFAIDV.> partition .PEOPLE.UOFAIDV..
10:23:16 BBD07700 SyncI: End inbound sync from server <.IDVPRD01.RESOURCES.UOFAIDV.> for partition .PEOPLE.UOFAIDV., Process succeeded.
10:23:16 BCD17700 OSync: Adding Partition mode psEntry for partition .PEOPLE.UOFAIDV. to PSQueue
10:23:16 92148700 OSync: Skulk Partition - change cache entry count 4 for .PEOPLE.UOFAIDV.
10:23:16 92148700 OSync: 2018/09/14 10:23:16 Start partition sync .PEOPLE.UOFAIDV. state:[0], type:[1].
10:23:16 92148700 OSync: Sync - Start outbound sync with (#=3, state=0, type=0 partition .PEOPLE.UOFAIDV.) .IDVPRD01.RESOURCES.UOFAIDV..
10:23:16 92148700 OSync: Sync - using version 9 on server <.IDVPRD01.RESOURCES.UOFAIDV.>.
10:23:16 92148700 OSync: Sending to ----> .IDVPRD01.RESOURCES.UOFAIDV.
10:23:16 92148700 OSync: Sync - sending updates to server <.IDVPRD01.RESOURCES.UOFAIDV.>.
10:23:16 92148700 OSync: Send Partition Updates started usingDispatcher=0
0 Likes
Knowledge Partner Knowledge Partner
Knowledge Partner

It looks like sync issue between different servers (I hope, that you have replicas of the same partitions on both servers).

Simple validation of this hypothesis:
You can look the same object information in iMonitor on one server and on another server.
Maybe you will see the differences.
0 Likes
Commander
Commander

Thanks al_b. I have validated the object I'm using for testing on both servers. You are correct, both hold a replica. IDVPRD01 holds a master and IDVPRD02 holds a read / write of all partitions.

It's worth noting that this problem appears to affect all user objects and not a select few.

I have another driver which has the DirXML-Assocaiations configured in the driver filter and an event is triggered on this driver after the failed migrate on the AD driver.

As you can see in the trace, the DirXML-Associations attribute of the user object is modified when triggering a migrate using a different driver.

<modify cached-time="20180914062036.967Z" class-name="User" event-id="IDVPRD01#20180914062036#3#1:11c5f417-0b5b-47ac-48a6-17f4c5115b0b" qualified-src-dn="O=PEOPLE\CN=a1999973" src-dn="\UOFAIDV\PEOPLE\a1999973" src-entry-id="186632" timestamp="1536906036#2">
<association state="associated">a1999973</association>
<modify-attr attr-name="DirXML-Associations">
<remove-value>
<value timestamp="1536905528#2" type="structured">
<component name="nameSpace">4</component>
<component name="volume">\UOFAIDV\RESOURCES\Driver Set\IDM4 Active Directory Driver</component>
<component name="path">8ed750ac88633345b7982d89c345d7a9</component>
</value>
</remove-value>
<add-value>
<value timestamp="1536906036#2" type="structured">
<component name="nameSpace">3</component>
<component name="volume">\UOFAIDV\RESOURCES\Driver Set\IDM4 Active Directory Driver</component>
<component name="path">8ed750ac88633345b7982d89c345d7a9</component>
</value>
</add-value>
</modify-attr>
</modify>
0 Likes
The opinions expressed above are the personal opinions of the authors, not of Micro Focus. By using this site, you accept the Terms of Use and Rules of Participation. Certain versions of content ("Material") accessible here may contain branding from Hewlett-Packard Company (now HP Inc.) and Hewlett Packard Enterprise Company. As of September 1, 2017, the Material is now offered by Micro Focus, a separately owned and operated company. Any reference to the HP and Hewlett Packard Enterprise/HPE marks is historical in nature, and the HP and Hewlett Packard Enterprise/HPE marks are the property of their respective owners.