Slow Journals?

Execution time comparison between NX Open .NET Journals and compiled programs.

Christian Mehlführer, User:Chmehl, Bradypus variegatus, CC BY 2.5

Table of Contents

Whether I rely on a Journal 1 or a compiled solution when implementing an NX add-on program depends on many different factors. If a certain programming language is intended for the implementation, there may not be a choice. C/C++ and Java must always be compiled. Python programs are always executed as scripts.

The .NET languages C# and VB.NET can be used in NX both compiled and uncompiled. The responsiveness and the processing speed can be important factors for the selection of one or the other variant. It is obvious that compiled .NET programs have a speed advantage. But how big is this difference actually? What is its effect in practice?

Background

Uncompiled .NET NX Open Journals are not interpreted at runtime. Each time the journal is called, the source code is compiled with the standard compiler in the .NET Framework, loaded and then regularly executed. During the program run you can find the corresponding assembly under the name journal.dll in the temporary directory used by NX. After completion of the program run, this dll is deleted each time by NX.

Interestingly, this means for the execution speed of the actual program content that compiled programs cannot have any advantage over uncompiled Journals. In the overall balance, however, the overhead for internal compilation is added. This overhead increases the response time of the application after the start.

Another aspect must also be taken into account. In the case of compiled programs, the unload option for the assembly can be specified (Immediately, At Termination, Explicitly). In the case of Journals, this option is ignored in the source code. The assemblies of journals are always unloaded after the end of the program (Immediately). If necessary, compiled programs can benefit from the fact that NX holds the assemblies in memory for re-execution.

Test Setup

Since, as shown, only the overhead for compiling and the unloading behavior matter, a very simple test program can be used. It only writes a marker to the NX log file.

using NXOpen;
using System;

public class SmallUi
{
    public static int Main(string[] args)
    {
        int retValue = 0;

        Session.GetSession().LogFile.WriteLine("%%%SUI");

        return retValue;
    }

    public static int GetUnloadOption(string arg)
    {
        return System.Convert.ToInt32(Session.LibraryUnloadOption.Immediately);
    }


}

To determine the influence of the size of the source code, another program was created that corresponds to the first program in terms of its content. In addition, the source code of a medium-sized real project was added in such a way that it is compiled but not executed. The result is a source code file with around 2700 lines.

A variant of both programs was created, compiled, and signed with the authoring license with the unloading option Immediately (directly after the end of the program) and At Termination (when exiting NX). The source codes of the short and long programs can also be executed directly as journals. This results in a total of 6 variants to be tested:

  • SUI: Short Program, compiled, unload immediately
  • SUAT: Short Program, compiled, unload at NX termination
  • SUIJ: Short Program, run as Journal
  • BUI: Long Programm, compiled, unload immediately
  • BUAT: Long Programm, compiled, unload at NX termination
  • BUIJ: Long Programm, run as Journal

To determine the execution time of those programs, there is also a small program that only writes a timestamp in the NX log file. In addition, a MenuScript file (.men) was written that creates an action button with a consecutive sequence of actions in NX for each of the 6 variants mentioned.

...
BUTTON SMALLUI
LABEL Small UI
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\small_ui.dll
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\time.dll
ACTIONS ${mypath}time\application\small_ui.dll
ACTIONS ${mypath}time\application\time.dll
...

In this way, the individual programs are executed immediately one after the other by NX at the push of a button. The timestamps and markers of the actual programs can be read from the log file for evaluation. The actual execution time of the variant to be tested can be determined from the distance between two timestamps enclosing a marker minus the distance between two directly consecutive timestamps. The first tests showed that outliers repeatedly occurred during the runtime of the time stamp program. This is why the timestamp program is called several times in succession and the median is used to calculate the execution times of the actual programs.

For each of the 6 program variants, 9 runs were carried out with a newly started NX. The execution times for the first and the second program call result from the median of these 9 runs. The values ​​determined are a measure of the response behavior of the various variants.

The tests were carried out under NX1953 on an older workstation with a Xeon CPU. The results can only be transferred qualitatively to other systems.

Results

Execution times of short program variants.
SUI: compiled, unload immediately.
SUAT: compiled, unload at termination of NX.
SUIJ: run as Journal.
(1): first run, (2): second run.

The figure shows the results for the short program variants. The full execution time for the compiled variants is just under 0.6 seconds when started for the first time (SUI (1), SUAT (1)). At the second start, the execution time is reduced to around 0.2 seconds if the dll was not unloaded beforehand (SUAT (2)). If the dll was unloaded (SUI (2)), the execution time corresponds to that of the initial start. The journal variants (SUIJ (1), SUIJ (2)) have a significantly longer execution time of around 1.2 seconds. The second run is slightly faster than the first.

Execution times of short program variants.
BUI: compiled, unload immediately.
BUAT: compiled, unload at termination of NX.
BUIJ: run as Journal.
(1): first run, (2): second run.

The figure shows the results for the long program variant. Here, too, the execution time for the compiled variants is just under 0.6 seconds at the first start (BUI (1), BUAT (1)) and 0.2 seconds at the second start if the dll has not been unloaded beforehand (BUAT (2 )). The uncompiled journal (BUIJ) has a slightly longer execution time of 1.4 seconds than the short version.

Conclusion

Overall, the measurements show no surprises. Uncompiled journals take significantly longer to start and stop than their compiled counterparts. Ideally, the response time to user interaction is less than a second (see e.g. 2 or 3). The compiled programs are all well below this mark. Journals show poorer response behavior. However, the values are not so high that the workflow is interrupted.

The influence of the source code size on the start time of the programs is small, compiled, and uncompiled.

Concerning the speed at which the actual program content runs, there is no difference between compiled and uncompiled applications.

If responsiveness plays a very important role, then compiled NX Open .NET applications are preferable. In all other cases, Journals can also be used.


  1. The term journal is often used in a broader sense for NX Open programs in general. Here, however, it is used only for programs implemented in VB.NET or C # that are executed directly from source code. ↩︎

  2. Michael Herczeg, Software-Ergonomie, Addison-Wessley 1994, S.203 ↩︎

  3. https://developer.gnome.org/hig-book/unstable/feedback-response-times.html.en ↩︎

Related