In the previous article I was showing how the Role and Resource objects get linked via a ResourceAssociation object, which the Roles and Resource Service Driver (RRSD) events upon and implements. But that example had an error with permissions, such that the RRSD object did not have sufficient eDirectory permissions to modify the User objects referenced and threw a -672 ERR_NO_ACCESS message.

I went and gave the object the RRSD driver was Security Equal To, more permissions on the User objects. Then the next thing I did was go the User Application interface and remove the Resource from the Role in the web interface.

This generated this event on the already existing ResourceAssociation object. Changed the nrfStatus from 50 to 15, which tells us we now know the following status values for ResourceAssociation objects. This might be a fun Wiki to set up and manage, so we could all benefit from group experimentation, since they have chosen not to document these values, for reasons that totally escape me. It does seem relevant to someone supporting an environment to know what the various status levels imply.

10 Granted
15 Revoked
30 Processing
50 Success
80 Error


Here is that Status change in detail:

[02/25/15 10:51:03.303]:rrsd ST:
<nds dtdversion="4.0" ndsversion="8.x">
  <source>
    <product edition="Evaluation" version="4.5.0.2">DirXML</product>
    <contact>NetIQ Corporation</contact>
  </source>
  <input>
    <modify cached-time="20150225185103.257Z" class-name="nrfResourceAssociation" event-id="idvault1#20150225185103#2#1:79f4f0d6-e491-47be-e1aa-d6f0f47991e4" qualified-src-dn="dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20150225103416-c5972c2204614d938d2c4b0765e02bc1" src-dn="\ACMEIDVAULT\system\service\idm\dvs0\userapp\AppConfig\RoleConfig\ResourceAssociations\20150225103416-c5972c2204614d938d2c4b0765e02bc1" src-entry-id="64800" timestamp="1424890263#2">
      <modify-attr attr-name="nrfStatus">
        <remove-value>
          <value timestamp="1424889256#162" type="int">50</value>
        </remove-value>
        <add-value>
          <value timestamp="1424890263#2" type="int">15</value>
        </add-value>
      </modify-attr>
    </modify>
  </input>
</nds>

As per all events through the RRSD process, it becomes a command sent to the shim to process.

[02/25/15 10:51:03.310]:rrsd ST:Submitting document to subscriber shim:
[02/25/15 10:51:03.310]:rrsd ST:
<nds dtdversion="4.0" ndsversion="8.x">
  <source>
    <product edition="Evaluation" version="4.5.0.2">DirXML</product>
    <contact>NetIQ Corporation</contact>
  </source>
  <input>
    <nrf:resourceassociation dn="dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20150225103416-c5972c2204614d938d2c4b0765e02bc1" event-id="0" xmlns:nrf="urn:dirxml:nrf"/>
  </input>
</nds>

The shim then traces out some information. It sees that the Role is assigned to two Users, so it checks to see if it needs to revoke their Resource. But since we had a 672 permission error in the previous attempt, they do not actually have the Resource assigned, so there is no work to actually do.

[02/25/15 10:51:03.312]:rrsd ST:: Processing resource association
        DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20150225103416-c5972c2204614d938d2c4b0765e02bc1
[02/25/15 10:51:03.314]:rrsd ST:: Retrieving resource association objects based on a role or resource DN. DN: dc=com\O=acmes\OU=users\OU=Active\OU=Employees\CN=john.cho
[02/25/15 10:51:03.314]:rrsd ST:: Retrieving resource association objects based on a role or resource DN. DN: dc=com\O=acmes\OU=users\OU=Active\OU=Others\CN=warren.smith

The shim just looks at the Resources the users have assigned, and decides to do nothing.

[02/25/15 10:51:03.325]:rrsd ST:SubscriptionShim.execute() returned:
[02/25/15 10:51:03.325]:rrsd ST:
<nds dtdversion="4.0">
  <source>
    <product instance="rrsd" version="4.5.0.0">NetIQ Role Service Driver</product>
    <contact>NetIQ Corporation</contact>
  </source>
  <output>
    <status event-id="0" level="success">Deleted resource association
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20150225103416-c5972c2204614d938d2c4b0765e02bc1</status>
  </output>
</nds>

Success, the resource assignment is removed, and the object representing it is deleted. All complete. Amusingly there is no nrfStatus for that state, since the object that would hold it is deleted.

Then I tried to add the Resource back to the Role in the web interface and got the same 672 error. Thus it was not the obvious permissions on the object it seems like it was reporting, rather it was the DN referenced attribute (the Role or the Resource) that it needed the permission to modify. This is because the nrfAssignedRoles and nrfAssignedResources attributes on a User (part of the nrfIdentity Aux class) are flagged in schema as Write Managed. This always confuses me, but it means you need permissions to the referenced object, to write its value to the current object, even if you have full permissions on the current object.

I find it easiest to think about it in the context of a Group. A group can be assigned to a user with multiple components. The User can have a Group Membership list, which is just a list of DN values. The Group can have a Member list, also a list of DN's. For completeness I will note it is actually the pairing of Security Equals on the User and Equivalent To Me on the Group that actually confers permissions in eDirectory, but that is not entirely the point here.

But if you as the modifier only had permission to the User and not the Group, you could potentially cause a security issue by just adding every permission group you wanted to the User with no checks or balances, since it is just a DN list. What the Write Managed flag does is require that the object referenced in the DN be manageable by you as well, which proves you have permissions to add this Group.

Similarly here in the case of the nrfAssignedRoles, which has a DN component in it as part of the Path syntax of the attribute. It is not a simple DN list, but since Path syntax includes a DN it can be flagged as Write Managed.

For completeness here is what it should look like when it succeeds in assigning the Resource to the Role, calculating who should have the resource and granting it to the appropriate user objects.

[02/25/15 11:03:34.898]:rrsd ST:SubscriptionShim.execute() returned:
[02/25/15 11:03:34.898]:rrsd ST:
<nds dtdversion="4.0">
  <source>
    <product instance="rrsd" version="4.5.0.0">NetIQ Role Service Driver</product>
    <contact>NetIQ Corporation</contact>
  </source>
  <output>
    <status event-id="0" level="success">Created resource request
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-35520eafbe454b87aa6ecc9e7e58b77f-0</status>
    <status event-id="0" level="success">Transitioned request status from 0 to 30
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-35520eafbe454b87aa6ecc9e7e58b77f-0</status>
    <status event-id="0" level="success">Transitioned request status from 30 to 30
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-35520eafbe454b87aa6ecc9e7e58b77f-0</status>
    <status event-id="0" level="success">Added assigned resource to user
                Resource: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceDefs\CN=CC-1010
                User: dc=com\O=acmes\OU=users\OU=Active\OU=Others\CN=warren.smith</status>
    <status event-id="0" level="success">Transitioned request status from 30 to 50
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-35520eafbe454b87aa6ecc9e7e58b77f-0</status>
    <status event-id="0" level="success">Created resource request
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-93099589fba54ef0ad54c27b1c7bac29-0</status>
    <status event-id="0" level="success">Transitioned request status from 0 to 30
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-93099589fba54ef0ad54c27b1c7bac29-0</status>
    <status event-id="0" level="success">Transitioned request status from 30 to 30
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-93099589fba54ef0ad54c27b1c7bac29-0</status>
    <status event-id="0" level="success">Added assigned resource to user
                Resource: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceDefs\CN=CC-1010
                User: dc=com\O=acmes\OU=users\OU=Active\OU=Employees\CN=john.cho</status>
    <status event-id="0" level="success">Transitioned request status from 30 to 50
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-93099589fba54ef0ad54c27b1c7bac29-0</status>
    <status event-id="0" level="success">Transitioned request status from 10 to 50
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20150225110334-a73bbe45704644d798b6fe16ab08beea</status>
    <status event-id="0" level="success">Modified resource association
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20150225110334-a73bbe45704644d798b6fe16ab08beea</status>
  </output>
</nds>

The key things to note are the line:

    <status event-id="0" level="success">Transitioned request status from 30 to 50
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20150225110334-35520eafbe454b87aa6ecc9e7e58b77f-0</status>

The newly created ResourceRequest is changed in status to 50, success, whereas before it went to 80 for error.

Then the overall completion, which to be fair, we saw before, even with the errors as:

    <status event-id="0" level="success">Modified resource association
                DN: dc=system\dc=service\dc=idm\CN=dvs0\CN=userapp\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20150225110334-a73bbe45704644d798b6fe16ab08beea</status>

Continuing in my idea of showing what events in the RRSD driver look like, the next one I saved to talk about it removing a Role to Resource association.

Here, the nrfResourceAssociation object exists and persists for the duration of the association. I am pretty sure there is no start/stop time on these objects so they need to stick around to maintain the linkage information.

This is an area where I am unclear and trying to better understand, the persistence of these linkage objects. In this case it is pretty clear they persist and ultimately are deleted only when the linkage is deleted. However in the case of an nrfRequest that is used for assigning a Role to a User, Group, Container, other Role, or Dynamic Group, I am not sure that they really persist. If they do not, what is the real indicator that RRSD uses to determine when recalculating their Roles?

There is a real consequence to the answer to this question. If you used LDAP or some tool to set the nrfAssignedRoles on a bunch of users, without making the nrfRequest objects for RRSD to do the work, will the RRSD recalculation work? If every time a user is reconsidered and the indicator of Role assignments in an nrfRequest, then you would expect any event that triggers the RRSD driver to look at the user, suddenly these manually created role assignments would go away. On the other hand, if the nrfRequest object only exists to trigger the RRSD to add, and only persists if there is an end date on the role assignment to be found when it is time to revoke it, then the manually setting of these nrfAssignedRoles would probably suffice to trigger RRSD to do its work and be mostly ok. I know that there is some Web Services call made at the end of a Role Assignment (see a previous article where an error connecting demonstrated that was happening, even if trace was not showing it.)

If anyone happens to understand this issue better, please leave a comment on this article. There is way to much of this part of the product that is a black box and it would be better to know more about the inner workings for everyone who uses the product.

Regardless, here is ResourceAssigment being removed. First we get this event:

[05/04/16 13:12:50.854]:ROLES ST:Processing events for transaction.
[05/04/16 13:12:50.855]:ROLES ST:
<nds dtdversion="4.0" ndsversion="8.x">
  <source>
    <product edition="Advanced" version="4.0.2.2">DirXML</product>
    <contact>Novell, Inc.</contact>
  </source>
  <input>
    <modify cached-time="20160504171250.818Z" class-name="nrfResourceAssociation" event-id="uiidm01#20160504171250#2#3:a752acce-febf-4482-36bf-ceac52a7bffe" qualified-src-dn="O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20160202140121-19db74a3af3e40a089cc46c6cd7ea769" src-dn="\UI_IDM\IDM\Services\driverSet\UserApplication\AppConfig\RoleConfig\ResourceAssociations\20160202140121-19db74a3af3e40a089cc46c6cd7ea769" src-entry-id="161164" timestamp="1462381970#2">
      <modify-attr attr-name="nrfStatus">
        <remove-value>
          <value timestamp="1454439679#40" type="int">50</value>
        </remove-value>
        <add-value>
          <value timestamp="1462381970#2" type="int">15</value>
        </add-value>
      </modify-attr>
    </modify>
  </input>
</nds>

The existing object with an nrfStatus of 50 (Success) is change to 15 (revoke/remove I guess). However, like all events through the RRSD driver, this gets converted to a 'command' which tells RRSD to re-examine the target object and redo all the needed work, outputting the delta changes.

[05/04/16 13:12:50.875]:ROLES ST:Submitting document to subscriber shim:
[05/04/16 13:12:50.875]:ROLES ST:
<nds dtdversion="4.0" ndsversion="8.x">
  <source>
    <product edition="Advanced" version="4.0.2.2">DirXML</product>
    <contact>Novell, Inc.</contact>
  </source>
  <input>
    <nrf:resourceassociation dn="O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20160202140121-19db74a3af3e40a089cc46c6cd7ea769" event-id="0" xmlns:nrf="urn:dirxml:nrf"/>
  </input>
</nds>

Then we see the work beginning as it calculates all the effective changes of this one fairly simple and straightforward event.

[05/04/16 13:12:50.876]:ROLES ST:: Processing resource association
        DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20160202140121-19db74a3af3e40a089cc46c6cd7ea769
[05/04/16 13:12:51.940]:ROLES ST:: Retrieving resource association objects based on a role or resource DN. DN: O=IDM\OU=Users\OU=Empl\CN=abrahat
[05/04/16 13:12:51.944]:ROLES ST:: Retrieving resource association objects based on a role or resource DN. DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceDefs\CN=SAP-UM-GRC-UserAccount

And so on, followed by thousands more of the same pattern of three lines in trace. This Role had thousands of members. It had a SAP GRC User Account entitlement associated it. I removed it (one event), and all the many thousands of members of the Role has to have their Resources revoked.

First we see it look at the specific ResourceAssociation, from which (not traced) it infers that everyone who was a member of the Role, thus lost the Resource, so need to revoke each one, one at a time. Alas this is static stamping of permissions, which bothers me, since eDirectory has such a nice inheritance model that it would have been so much more efficient to use that for Roles permissions. However as I think about it, the issue remains that we need an event to trigger these sorts of tasks, so that the end node Entitlement can be changed as needed.

If Roles were just about permissions in eDirectory that would be great, but since it has to trigger a driver (or many) based on an inheritance change, we need some way of triggering it. I still think there ought to have been some way to make that happen if they were being clever enough.

Having looked at the Role the Resource is being removed from, it starts working on each member and recalculates their Resource entitlements (I am guessing it likely looks at their Roles as well but cannot prove that) and then it looks at the Resource to update as well.

It then repeats this for all the thousands of users.

This is probably the major lesson of large scale RBPM implementations with this approach. The inheritance model, using static stamping of permissions means seemingly minor changes can take long periods of time to implement and it would be wise to think carefully before making changes in production.

Finally we get to the end where we see:

[05/04/16 13:13:33.347]:ROLES ST:SubscriptionShim.execute() returned:
[05/04/16 13:13:33.347]:ROLES ST:
<nds dtdversion="3.6.1">
  <source>
    <product instance="Role and Resource Service Driver" version="4.0.0.6430">Novell Role Service Driver</product>
    <contact>Novell, Inc.</contact>
  </source>
  <output>
    <status event-id="0" level="success">Created resource request
                DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20160504131332-1ea26697968b47a0ae70a9b8f9b2396c-0</status>
    <status event-id="0" level="success">Transitioned request status from 0 to 30
                DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20160504131332-1ea26697968b47a0ae70a9b8f9b2396c-0</status>
    <status event-id="0" level="success">Removed assigned resource from user
                Resource: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceDefs\CN=SAP-UM-GRC-UserAccount
                User: O=IDM\OU=Users\OU=inactive\CN=williamt</status>
    <status event-id="0" level="success">Transitioned request status from 30 to 50
                DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20160504131332-1ea26697968b47a0ae70a9b8f9b2396c-0</status>
    <status event-id="0" level="success">Deleted resource association
                DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20160202140121-19db74a3af3e40a089cc46c6cd7ea769</status>
  </output>
</nds>

There is a Resource Request created to revoke the Resource, it transition from 0 to 30 (was created and now being processed). It removes the Resource. Then the status changes from 30 to 50 which is success, and finally the Resource Association object that started this all is deleted.

[05/04/16 13:13:33.353]:ROLES ST:
DirXML Log Event -------------------
     Driver:   \UI_IDM\IDM\Services\driverSet\Role and Resource Service Driver
     Channel:  Subscriber
     Status:   Success
     Message:  Created resource request
                DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20160504131332-1ea26697968b47a0ae70a9b8f9b2396c-0
[05/04/16 13:13:33.355]:ROLES ST:Processing operation <status> for .
[05/04/16 13:13:33.355]:ROLES ST:
DirXML Log Event -------------------
     Driver:   \UI_IDM\IDM\Services\driverSet\Role and Resource Service Driver
     Channel:  Subscriber
     Status:   Success
     Message:  Transitioned request status from 0 to 30
                DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20160504131332-1ea26697968b47a0ae70a9b8f9b2396c-0
[05/04/16 13:13:33.356]:ROLES ST:Processing operation <status> for .
[05/04/16 13:13:33.357]:ROLES ST:
DirXML Log Event -------------------
     Driver:   \UI_IDM\IDM\Services\driverSet\Role and Resource Service Driver
     Channel:  Subscriber
     Status:   Success
     Message:  Removed assigned resource from user
                Resource: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceDefs\CN=SAP-UM-GRC-UserAccount
                User: O=IDM\OU=Users\OU=inactive\CN=williamt
[05/04/16 13:13:33.358]:ROLES ST:Processing operation <status> for .
[05/04/16 13:13:33.358]:ROLES ST:
DirXML Log Event -------------------
     Driver:   \UI_IDM\IDM\Services\driverSet\Role and Resource Service Driver
     Channel:  Subscriber
     Status:   Success
     Message:  Transitioned request status from 30 to 50
                DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceRequests\CN=20160504131332-1ea26697968b47a0ae70a9b8f9b2396c-0
[05/04/16 13:13:33.360]:ROLES ST:Processing operation <status> for .
[05/04/16 13:13:33.360]:ROLES ST:
DirXML Log Event -------------------
     Driver:   \UI_IDM\IDM\Services\driverSet\Role and Resource Service Driver
     Channel:  Subscriber
     Status:   Success
     Message:  Deleted resource association
                DN: O=IDM\OU=Services\CN=driverSet\CN=UserApplication\CN=AppConfig\CN=RoleConfig\CN=ResourceAssociations\CN=20160202140121-19db74a3af3e40a089cc46c6cd7ea769
[05/04/16 13:13:33.362]:ROLES ST:End transaction.

You can see the Status events above, in case you have trace at level 1 or 2 for the same info you would get at level 3. This is useful since trace does slow the driver down. However in the case of the RRSD drive, since so little of the actual hard work is done in policy, rather almost all of it is done inside the shim, tracing to the log file, the slow down of level 3 would be minimal. The hard part that slows down level 3 trace is more related to rendering the event document as XML in text. The engine stores the XML in memory in a binary format as a DOM (Document Object Model) that is pretty efficient in space and memory. However for human consumption it is shown as a text representation. Converting between the two formats can be processor intensive, and if there is no tracing going on, then the engine does not actually waste any time doing the conversion.

Thus turning a policy heavy driver to level 3 trace can slow it down, often as much as a 10 times slower or more. Large loops as well, when traced can really slow it down. For example if you had a query for all groups in a system and instead of letting the Input Transform do some work on it, <instance> by <instance> document inside the <output> document, but instead looped over the <instance> nodes and did what was required, that rendering of each time through the loop seems to really slow the engine down. Even though there is little rendering of DOM to text at that point. There is some rendering of each node of the node set being processed that is shown that might be involved but I think it is the work of the loop itself that causes the slowdown.

As noted in the various articles in this series, the RRSD driver does not have a lot of policy in its configuration. Mostly it maps events on an object class to a command. Thus level 3 trace is probably less of a bottle neck than on almost any other driver. The other major bottle neck I am aware of in this driver is the Dynamic Group reprocessing. The closest thing to dynamic inheritance that this shim does is the use of Dynamic Groups, whose membership is effectively determined by an LDAP filter. Alas, the shim does not seem to seek out all the Roles assigned to such groups, and then persist a connection monitoring the member list. There is an LDAP extension (not sure if there is an NCP/JClient analog) that allows a persistent connection to basically get events when the member list of a dynamic group changes (because some other changed caused a new object to 'fall into' or 'fall out of' the filter results.

That would be a cool enhancement if they could implement it. However, if there are many Roles assigned to dynamic groups, it APPEARS that the RRSD re-evaluates the entire member list each time, or at least reconsiders it, which severely slows it down in large environments.

The interval between checks can be made larger, but still needs to happen.

That is all I have trace sample wise right now. As always I keep an eye open for interesting examples to write about, and you should as well!