Performance considerations: event handlers

Lately I’ve been involved quite a bit in performance analysis and tuning on Ax 2012. It’s not only important to solve the customer’s requirements but at the same time the solution must be implemented in a way that its processing ends before the heath death of the universe.

There’s are lot to say about performance but for now I’ll just stick to a quick heads-up about event handlers and delegates. And to boot I can demonstrate it without worrying about customer specific information.

Eventing was added to Ax 2012 but it’s not widely used in the standard code (if at all). Despite the potentially cleaner design, I’ve seen some instances where it caused some issues.

I decided to try to measure the overhead caused by eventing, ignoring whatever business logic they might perform. The results were beyond my expectations.

My test setup is a simple class with empty methods for different scenarios. The test was performed on an Ax 2012 R3 demo VM.

Class_EventHandlerTester

On the method runWithAOTSubscription a post event handler is defined that calls theAOTHandler. Method runWithDelegateSubscription calls theDelegate to which theDelegateMethod is subscribed using the eventHandler function. Lastly, runWithMethod directly calls theMethod without any events in between.

In main() every scenario is executed 100000 times.

public static void main(Args _args)
{
    EventHandlerTester eht = new EventHandlerTester();
    int i;
    int maxLoops = 100000;
    ;
 
    for(i=1; i<=maxLoops; i++)
    {
        eht.runWithAOTSubscription();
    }
 
    eht.theDelegate += eventhandler(EventHandlerTester::theDelegateMethod);
    for(i=1; i<=maxLoops; i++)
    {
        eht.runWithDelegateSubscription();
    }
 
    for(i=1; i<=maxLoops; i++)
    {
        eht.runWithMethod();
    }
}

Using the trace parser I found some interesting results. I ran it a couple of times and results were consistent.
EventHandlerTraceResults01

The event handlers subscribed using eventHandler are by far the worst. When looking at the call tree it’s fairly obvious why: there seems to be a lot of bookkeeping going on internally.
EventHandlerTraceResults02

Event handlers defined in the AOT are an improvement, even though it’s the only scenario which uses a parameter (XppPrePostArgs). This could make matters worse but actually it doesn’t.
EventHandlerTraceResults03

And as expected it’s still quicker when calling a method directly.
EventHandlerTraceResults04

Now why did I bother investigating this? Because I’ve seen the effect of using event handlers on data methods of often used tables. Even ignoring the body of the event handlers, the simple fact of calling the event handler has a noticeable performance cost. I’m not advocating against the use of event handlers but beware of them when they’re part of code involved in a performance problem.

If you’d like to test this yourself you can use the XPO. Let me know if you have other results or if my approach is flawed (it was getting late when I came up with the idea :)).

Can’t define abstract or final methods on abstract table

It seems Ax doesn’t allow you to use abstract or final on abstract tables. When adding abstract public myMethod() to an abstract table (e.g. EcoResProduct), you get this compile error:

Conflicting access modifier given.

The error message doesn’t really make sense because the only access modifier specified is public. I’m not sure if this is intended behaviour or an issue with the compiler. There’s a whitepaper that mentions you can’t declare a table as final but it doesn’t say anything about the methods. In any case, a more meaningful error message would help.

This was discovered on Ax 2012 R2 CU7 but we could reproduce it in the Ax 2012 R3 CU8 demo machine.

To enforce overrides on derived tables you can still use the old school method like so:

public void myMethod()
{
    throw error(Error::missingOverride(funcName()));
}

Yet another cause of Ax 2012 logon errors

Recently I ran into this error when users tried to log on to a second partition.

A user session on the server could not be created. Try to start the client again. If the problem continues, contact the Microsoft Dynamics Ax administrator.

It’s weird, because I had just added users with the Active Directory Import Wizard. They already had access to the initial partition and I had no trouble accessing the second partition with my own account. Because of that, none of the solutions I found online worked: the transaction log wasn’t full, the CREATEUSERSESSIONS stored procedure wasn’t broken and the config file was correct.

After comparing records in the UserInfo table I noticed that the new records had no values in the fields Language and HelpLanguage. They are, however, mandatory fields in Ax. They’re also used in CREATEUSERSESSIONS. After setting a value in both fields the problem disappeared. And so peace and productivity returned to the office and everyone was happy.

Well, I wasn’t happy. How is it possible that mandatory fields don’t have any values? I used a standard Ax tool to add the users to the system. After digging through the code it turns out (hooray for cross-references) that a bunch of values for the UserInfo record are copied from user Admin. Sure enough, there was no Language or HelpLanguage defined on that record. For some unknown reason, those values were gone and caused invalid UserInfo records to be created.

I fixed the data for user Admin and never had that problem again. Now I was happy too.

Inconsistent behavior between X++ and CIL using tables with inheritance

This one is a doozy. Recently a customer contacted me because they were having problems running a job they made themselves to export product information. It seemed to work fine in the client during development but the results when running in batch were very different.

Starting from a query on EcoResProduct they collect a lot of information and export it to a file which is picked up by another application. Sounds simple enough. It certainly is a lot easier than putting a fridge on a comet.

What they were trying to do came down to this:

    query = new Query();
 
    qbds = query.addDataSource(tableNum(EcoResProduct));
 
    queryRun = new QueryRun(query);
 
    while (queryRun.next())
    {
        ecoResProduct = queryRun.get(tableNum(EcoResProduct));
 
        // Look up information in related tables, sometimes using table ID
    }

Nothing extraordinary going on there. Until they put it in batch. As it turns out ecoResProduct.TableId was no longer correct and because of that they couldn’t find some related records.

While debugging I noticed that when running in batch the variable ecoResProduct was actually of type EcoResDistinctProduct. I could see it happening in Visual Studio. When running the job in my client and using the X++ debugger the variable was of type EcoResProduct.

Then it clicked for me: it looks like the CIL version of the code handles abstract base tables differently. It makes sense actually, because you can’t create instances of abstract types, only of derived concrete types. In X++ it is somehow supported for instances of table buffers to be abstract types. I decided to test my hypothesis with another infamous table using inheritance: DirPartyTable. I made a small class with a simple method to run a query on the table and get some records from it.

static container doStuff(container _params = conNull())
{
    DirPartyTable dirPartyTable;
    QueryRun queryRun;
    Query query;
    QueryBuildDataSource qbds;
 
    TableId tableId = tableNum(DirPartyTable);
 
    int i;
    ;
 
    query = new Query();
 
    qbds = query.addDataSource(tableId);
 
    queryRun = new QueryRun(query);
 
    while (queryRun.next())
    {
        dirPartyTable = queryRun.get(tableId);
 
        info(strFmt('Expected ID: %1, Real ID: %2',
                tableId, dirPartyTable.TableId));
 
        ++i;
 
        if (i > 5)
            break;
    }
 
    return conNull();
}

I then called the method in 2 ways:

server static private void runXpp()
{
    setPrefix(funcName());
    TestQueryTableId::doStuff();
}
server static private void runCIL()
{
    container ret;
    XppILExecutePermission  xppILExecutePermission;
    ;
 
    setPrefix(funcName());
 
    xppILExecutePermission = new XppILExecutePermission();
    xppILExecutePermission.assert();
 
    ret = runClassMethodIL(classStr(TestQueryTableId),
                        staticMethodStr(TestQueryTableId, doStuff),
                        conNull());
 
    CodeAccessPermission::revertAssert();
}

The results were exactly what I expected.

Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303

Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2377
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2978
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2978
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2978
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2975
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2975

Luckily it can be fixed with SysDictTable::getRootTable().

        info(strFmt('Expected ID: %1, Real ID: %2, Fixed ID: %3',
                tableId, dirPartyTable.TableId, SysDictTable::getRootTable(dirPartyTable.TableId)));

Giving me this:

Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runXpp	Expected ID: 2303, Real ID: 2303, Fixed ID: 2303

Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2377, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2978, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2978, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2978, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2975, Fixed ID: 2303
Info	TestQueryTableId.run\TestQueryTableId::runCIL	Expected ID: 2303, Real ID: 2975, Fixed ID: 2303

The problem was discovered in Ax 2012 R2 but I ran the test on and R3 demo machine and the results were exactly the same.

Quite confusing and time consuming to figure out what’s going on.

Ax 2012 X++ editor extensions

If you’re developing in Ax 2012 and you’re not yet using the editor extensions immediately stop what you’re doing and head over to Codeplex to download the extensions. Installing them is as easy as copying a couple of files to the Ax client directory.

They’re really useful and I’m a bit annoyed when I log on to a system where they’re not installed. Now stop reading and go.

Don’t forget the correct method signature when using runClassMethodIL()

If you think you know how something works, but really don’t and you’re not paying attention when errors pop up then you’re going to have a bad time.

So if you write this:

static private void myMethod()
{
    info(funcName());
}

Or this:

static private void myMethod(container _container)
{
    info(funcName());
}

Or this:

static private container myMethod()
{
    info(funcName());
    return conNull();
}

To use like this:

server static public void runIL()
{
    container ret;
    XppILExecutePermission  xppILExecutePermission;
    ;
 
    xppILExecutePermission = new XppILExecutePermission();
    xppILExecutePermission.assert();
 
    ret = runClassMethodIL(classStr(MyClass), staticMethodStr(MyClass, myMethod), conNull());
 
    CodeAccessPermission::revertAssert();
}

Then you’ll get this error at runtime and be confused.

Error executing code: MyClass object does not have method 'myMethod'.

The method is right there, how can it not exist? You try some variations but the error remains. Confusion intensifies. After few minutes of grumbling and hasty attempts to fix it common sense kicks in and you understand the correct way to write it is:

static private container myMethod(container _container = conNull())
{
    info(funcName());
    return conNull();
}

Which makes perfect sense once you think about it because it’s the only way to get values in and out of the method. Of course, this could have been avoided by taking a step back and thinking a bit before typing.

Bonus tip for dealing with this runtime error:

Request for the permission of type 'XppILExecutePermission' failed.

Check if your method calling runClassMethodIL() and creating the permission (runIL() in my example) is actually running on server. If not, runClassMethodIL() won’t find the XppILExecutePermission object because it’s on another tier.