Hi! I want to know how long different operations take. To find out, I've written a small performance test which executes different statements multiple times, and then checks how long the execution took. It works quite fine in simulation mode, with 50000 loops of each statement.

On real hardware, however, it does not: As soon as I go over ~200 loops, Codesys online communication will stop. This was expected, but what is strange is that you cannot go online even after the performance test is done, ie when the cycle time is good again. So either the runtime gets stuck in some strange error state, or it crashes altogether. If anyone has a clue of why this happens, or want to improve on the performance test in general, I'd be happy. Code will follow in comment, since the board does not allow attachements. (Why?)

perftest.exp:

( @NESTEDCOMMENTS := 'Yes' )
( @PATH := '' )
( @OBJECTFLAGS := '0, 8' )
( @SYMFILEFLAGS := '2048' )
FUNCTION_BLOCK DummyFB
VAR_INPUT
invar: BOOL;
END_VAR
VAR_OUTPUT
outvar: BOOL;
END_VAR
VAR
END_VAR
( @END_DECLARATION := '0' )
outvar := invar;
END_FUNCTION_BLOCK

( @NESTEDCOMMENTS := 'Yes' )
( @PATH := '' )
( @OBJECTFLAGS := '0, 8' )
( @SYMFILEFLAGS := '2048' )
FUNCTION DummyFunc : BOOL
VAR_INPUT
END_VAR
VAR
END_VAR
( @END_DECLARATION := '0' )
DummyFunc := TRUE;
END_FUNCTION

( @NESTEDCOMMENTS := 'Yes' )
( @PATH := '' )
( @OBJECTFLAGS := '0, 8' )
( @SYMFILEFLAGS := '2048' )
FUNCTION NanoSecsSince : DWORD
VAR_INPUT
start: TIME;
END_VAR
VAR
END_VAR
( @END_DECLARATION := '0' )
NanoSecsSince := TIME_TO_DWORD(TIME() - start) * 1000000;
END_FUNCTION

( @NESTEDCOMMENTS := 'Yes' )
( @PATH := '' )
( @OBJECTFLAGS := '0, 8' )
( @SYMFILEFLAGS := '2048' )
PROGRAM PLC_PRG
VAR CONSTANT
MAXLOOPS: DWORD := 50000;
END_VAR
VAR
loops: DWORD;
state: BYTE;
x: DWORD;
start: TIME;
cycletime: TIME;
nanosecs: DWORD;

my_fb: DummyFB;
my_byte: BYTE;
my_int: INT;
my_word: WORD;
my_real: REAL;
my_short_str: STRING := 'ab';
my_long_str: STRING(255) := '01234567890abcdef01234567890abcdef01234567890abcdef01234567890abcdef01234567890abcdef01234567890abcdef01234567890abcdef01234567890abcdef01234567890abcdef01234567890abcdef';
my_2d_array: ARRAY[0..7] OF INT := 0, 1, 2, 3, 4, 5, 6, 7;
my_ton: TON;

(* Results *)
for_loop: DWORD;
function_call: DWORD;
fb_call: DWORD;
int_div: DWORD;
float_div: DWORD;
str_len_short: DWORD;
str_len_long: DWORD;
array_index: DWORD;
timer_call: DWORD;

END_VAR

( @END_DECLARATION := '0' )
start := TIME();

IF state = 0 THEN
loops := MAXLOOPS;
END_IF

FOR x := 1 TO loops DO
CASE state OF

(* First 10 cycles are warmup *)
0:
    for_loop := 0;

10: (* Measured no-op - for_loop*)
    ;

21: (* function_call *)
    DummyFunc();

22: (* fb_call *)
    my_fb(invar := TRUE);

30: (* int_div *)
    my_word := 4711 / 17;

31: (* float_div *)
    my_real := 4711.1 / 17.1;

40: (* str_len_short *)
    my_int := LEN(my_short_str);

41: (* str_len_long *)
    my_int := LEN(my_long_str);

50: (* array_index *)
    my_int := my_2d_array[4];

60: (* timer_call *)
    my_ton(IN:= TRUE, PT:= T#1h);

100: (* stop test *)
    loops := 0;

END_CASE;

END_FOR

IF loops > 0 THEN
nanosecs := NanoSecsSince(start) / LOOPS - for_loop;

CASE state OF

10: (* Measured no-op *)
    for_loop := nanosecs;

21:
    function_call := nanosecs;

22:
    fb_call := nanosecs;

30:
    int_div := nanosecs;

31:
    float_div := nanosecs;

40:
    str_len_short := nanosecs;

41:
    str_len_long := nanosecs;

50:
    array_index := nanosecs;

60:
    timer_call := nanosecs;

END_CASE;

state := state + 1;

END_IF

cycletime := TIME() - start;

END_PROGRAM

( @NESTEDCOMMENTS := 'Yes' )
( @GLOBAL_VARIABLE_LIST := 'Global_Variables' )
( @PATH := '' )
( @OBJECTFLAGS := '0, 8' )
( @SYMFILEFLAGS := '2048' )
VAR_GLOBAL
END_VAR

( @OBJECT_END := 'Global_Variables' )
( @CONNECTIONS := Global_Variables
FILENAME : ''
FILETIME : 0
EXPORT : 0
NUMOFCONNECTIONS : 0
)

( @NESTEDCOMMENTS := 'Yes' )
( @GLOBAL_VARIABLE_LIST := 'Variable_Configuration' )
( @PATH := '' )
( @OBJECTFLAGS := '0, 8' )
( @SYMFILEFLAGS := '2048' )
VAR_CONFIG
END_VAR

( @OBJECT_END := 'Variable_Configuration' )
( @CONNECTIONS := Variable_Configuration
FILENAME : ''
FILETIME : 0
EXPORT : 0
NUMOFCONNECTIONS : 0
)

_ALARMCONFIG
_ALARMCONFIGNEXTTEXTID : 10002
_ALARMCONFIGFORMATS : 'HH$':$'mm$':$'ss','dd$'-$'MM$'-$'yyyy'
_ALARMCLASSLIST : 1
_ALARMCLASSID : 0
_ALARMCLASSACKTYPE : 0
_ALARMCLASSNAME : 'DEFAULT'
_ALARMCLASSDESCRIPTION : ''
_ALARMCLASSBGCOLORS : 16777215,16777215,16777215
_ALARMCLASSTEXTCOLORS : 3394560,255,16711680
_ALARMCLASSBITMAPS : '','',''
_ALARMACTIONLIST : 0
( @ALARMCLASSRESETCOLORS := '_ALARMCLASSRESETCOLORS: 33023,16777215' )
( @ALARMCLASSRESETBITMAP := '_ALARMCLASSRESETBITMAP: $'$'' )
_ALARMGROUPLISTNAME : 'System'
_ALARMGROUPPATH : 'System'
_ALARMGROUPLIST : 0
_VISUALSETTINGSFLAGS : 0,0,0,0
_VISUALSETTINGSFLAGS : '','',''
_VISUALSETTINGSDYNTEXTFILECOUNT : 0

( @ALARMCONFIGFLAGS := '_ALARMCONFIGFLAGS: 4' )
( @ALARMCONFIGGLOBALDB_STR := '_ALARMCONFIGGLOBALDB_STRINGS: $'$',$'$',$'$',$'$'' )
( @ALARMCONFIGGLOBALDB_NUM := '_ALARMCONFIGGLOBALDB_NUMBERS: 0,0' )
_END_ALARMCONFIG

LIBRARY
STANDARD.LIB 4.10.05 11:14:46
( @LIBRARYSYMFILEINFO := '0' )
NumOfPOUs: 21
CONCAT: 0
CTD: 0
CTU: 0
CTUD: 0
DELETE: 0
F_TRIG: 0
FIND: 0
INSERT: 0
LEFT: 0
LEN: 0
MID: 0
R_TRIG: 0
REPLACE: 0
RIGHT: 0
RS: 0
RTC: 0
SEMA: 0
SR: 0
TOF: 0
TON: 0
TP: 0
NumOfGVLs: 0
END_LIBRARY

PLC_CONFIGURATION
_GLOBAL
_VERSION: 3
_AUTOADR: 1
_CHECKADR: 1
_SAVECONFIGFILESINPROJECT: 0
_END_GLOBAL

_MODULE: '3S'
_SECTION_NAME: 'not_found'
_INDEX_IN_PARENT: '-1'
_MODULE_NAME: 'not_found'
_NODE_ID: 0
_IECIN: %IB0
_IECOUT: %QB0
_IECDIAG: %MB0
_DOWNLOAD: 1
_EXCLUDEFROMAUTOADR: 0
_COMMENT: ''
_END_MODULE
PLC_END

RESOURCE

END_RESOURCE

_WORKSPACE
_GLOBALVISUALSETTINGS
_VISUALSETTINGSFLAGS : 0,0,0,0
_VISUALSETTINGSFLAGS : '','',''
_VISUALSETTINGSDYNTEXTFILECOUNT : 0
_VISUALBITMAPLISTCOUNT : 0
_END_GLOBALVISUALSETTINGS
_END_WORKSPACE

MACRO
MacroName: 'export'
MacroMenu: '&export'
MacroCmd: 'query off ok'
MacroCmd: 'project export project.exp'
MacroCmd: ''
END_MACRO

your loops are taking too long, so the PLC will have a watchdog alarm and resets and starts all over when nothing is done to prevent ths.

In ST you have to make sure the program is completed in watchdog time
As with most machines you will not get a good answer to this as a PLC needs time to update i/o and communication etc.
the time is updated via a counter internal, so it will be on time

by the way if you mul by 1000000 you do not get a better result as it is a DWORD. just leave it like it is.
you will have to break up your program in subs

shooter hat geschrieben:
your loops are taking too long, so the PLC will have a watchdog alarm and resets and starts all over when nothing is done to prevent ths.
In ST you have to make sure the program is completed in watchdog time
As with most machines you will not get a good answer to this as a PLC needs time to update i/o and communication etc.
the time is updated via a counter internal, so it will be on time

The cycle time is not very long, about 2000 us. I have other programs running on the same device with such cycle time without problems. It must be something more to this problem.