Eclipse Community Forums: 4DIAC - Framework for Distributed Industrial Automation and Control

Home » Eclipse Projects » 4DIAC - Framework for Distributed Industrial Automation and Control » Timer function block accuracy(Testing with E_TRAIN/E_DELAY function block shows timing accuracy is variable)

Timer function block accuracy [message #1832374]

Thu, 17 September 2020 05:12

Eclipse User

Hi,

I'm just wondering if you might be able to help me out? Our QA team mentioned they have highly variable timing response/accuracy with the E_DELAY function block.

I had a look at what they were trying to do and we optimised a few things but when I went and did some more testing with just the E_DELAY, I found they were right.

I created this simple application:
index.php/fa/38922/0/

Then I modified the E_DELAY so that every 100 event triggers, debug is printed showing min/average/max timing error (that is how much time difference between required trigger point and actual trigger point) . There is a 2s delay after the data is printed out to ensure the output doesn't skew the next sample of 100 triggers.

I did the following test on a VM, load average was zero and CPU was around 1% during the test. Here are some results running on VM:
min:0.14ms averr:4.14ms max:8.44ms
min:0.01ms averr:0.69ms max:2.77ms
min:0.01ms averr:0.49ms max:7.69ms
min:0.04ms averr:0.61ms max:5.95ms
min:0.00ms averr:0.45ms max:4.88ms
min:0.01ms averr:0.64ms max:14.76ms
min:0.02ms averr:0.47ms max:3.28ms
min:0.01ms averr:0.74ms max:3.54ms
min:0.01ms averr:0.45ms max:3.15ms
min:0.04ms averr:0.79ms max:1.94ms
min:0.00ms averr:1.26ms max:3.42ms
min:0.02ms averr:6.62ms max:9.73ms
min:0.02ms averr:0.59ms max:1.22ms
min:0.01ms averr:0.63ms max:6.59ms
min:0.00ms averr:0.57ms max:1.60ms

Here are some results running on embedded system (physical hardware). The results from the embedded platform are with load average around 0.6 with CPU usage around 50% during testing.
min:0.52ms averr:222.58ms max:270.83ms
min:0.13ms averr:99.14ms max:287.23ms
min:0.04ms averr:17.15ms max:30.24ms
min:1.82ms averr:7.47ms max:19.82ms
min:1.05ms averr:17.54ms max:26.48ms
min:0.02ms averr:154.94ms max:300.33ms
min:0.41ms averr:10.82ms max:21.61ms
min:0.04ms averr:11.65ms max:25.38ms
min:0.12ms averr:12.38ms max:25.19ms
min:0.05ms averr:193.69ms max:281.31ms
min:0.05ms averr:53.49ms max:303.39ms
min:0.05ms averr:0.90ms max:5.05ms
min:0.15ms averr:14.10ms max:22.18ms
min:109.92ms averr:298.67ms max:325.43ms

I checked the tick/time parameters in CMakeLists.txt and they are set to default values:
SET(FORTE_TicksPerSecond "1000" CACHE STRING "forte sticks per second")
SET(FORTE_TimeBaseUnitsPerSecond "1000000000" CACHE STRING "Defines the time base in units per second that will be used in the TIME data type, The default value 1000000000 means 1ns")

I added some debug on start to confirm the tick parameter:
Forte ticks per second:1000

I wrote a small threaded producer/consumer application to simulate the event and ticking in forte to see if there is any issue with system clock / threading / mutex but average error and max error values were down in the micro seconds.

I then went into the forte code looking at how I could debug what the issue is but I got a bit lost in the threaded implementation and reasoning for critical sections, etc.

I'm wondering:

Have you seen this issue before and is there a solution?
Can you give me any tips on how to debug this issue?
Do you have any suggestions on what the issue might be?

Thank you.

Attachment: e_train_application.PNG
(Size: 11.24KB, Downloaded 475 times)

Re: Timer function block accuracy [message #1832432 is a reply to message #1832374]

Thu, 17 September 2020 15:29

Eclipse User

I've hear once that people trying to do periodic things with an E_DELAY had troubles. But this was more due to their application design and therefore I didn't investigate further.

I had a look on the code and triggering an E_DELAY and processing the response requires quite some interlocking (two mutexes, one semaphore). Even though two of the locks should in your setup always be free there is a chance for at least for one causing some of the troubles. I've found one place in timerha.cpp that could partly be responsible. Can you give it a try if it improves your situation. If not then we have to dig deeper on the different critical sections involved in that case.

Attachment: timerha.cpp
(Size: 4.00KB, Downloaded 90 times)

Re: Timer function block accuracy [message #1832437 is a reply to message #1832432]

Thu, 17 September 2020 21:06

Eclipse User

Hi Alois,

Thank you for the reply. I applied the timerha.cpp, recompiled and the results follow.

This is with forte running on VM:
min:0.60ms averr:931.04ms max:1861.93ms
min:2.36ms averr:933.96ms max:1864.69ms
min:0.44ms averr:930.48ms max:1861.07ms
min:1.44ms averr:932.12ms max:1863.75ms
min:0.44ms averr:930.66ms max:1862.45ms
min:0.47ms averr:931.18ms max:1861.96ms
min:0.56ms averr:930.84ms max:1861.23ms
min:0.31ms averr:930.73ms max:1861.97ms
min:1.14ms averr:930.45ms max:1861.83ms

This is with forte running on (physical) embedded:
min:0.09ms averr:198.35ms max:325.65ms
min:0.07ms averr:55.33ms max:326.80ms
min:0.22ms averr:36.08ms max:63.16ms
min:0.16ms averr:32.98ms max:55.16ms
min:88.90ms averr:268.50ms max:284.40ms
min:0.13ms averr:162.92ms max:334.49ms
min:0.04ms averr:17.45ms max:40.68ms
min:0.13ms averr:18.41ms max:40.12ms
min:0.06ms averr:20.96ms max:38.46ms
min:0.32ms averr:190.81ms max:309.04ms

Please let me know if you would like me to do anything else.

Thank you

Re: Timer function block accuracy [message #1832453 is a reply to message #1832437]

Fri, 18 September 2020 05:48

Eclipse User

Am I reading the numbers right that it got worse?

You are measuring the time between the reception of the start event and the sending of the EO event, aren't you?

I have some idea of improving the timerhandler to make less use of the mutex. This would really be an improvement in resource usage. But it would take a bit of my time. Would it be possible that you give me your application and the adapted delay so that I can do some experiments on my machine?

Re: Timer function block accuracy [message #1832539 is a reply to message #1832453]

Sun, 20 September 2020 21:47

Eclipse User

Hi,

Please find attached the files. My apologies in advance for the poor coding, the changes were only meant for testing purposes.

The timing is trying to determine when an event should occur and calculates how much time the event missed its designated interval.

Please let me know if I can do anything else to help.

Thank you.

Attachment: workspace.zip
(Size: 430.07KB, Downloaded 169 times)
Attachment: E_DELAY.cpp
(Size: 3.23KB, Downloaded 108 times)
Attachment: E_DELAY.h
(Size: 1.48KB, Downloaded 99 times)

Re: Timer function block accuracy [message #1832604 is a reply to message #1832539]

Mon, 21 September 2020 12:48

Eclipse User

Thanks for the code. Yes this better helps to understand your measurements. I have some trouble with it. The point is you are not purely measuring the behavior of the E_DELAY and the timer infrastructure but also the event handling mechanism in 4diac FORTE. The reason is that you are measuring the time between two START events. As you are inside an E_TRAIN this should roughly work but you are in addition to the E_DELAY also measuring the performance of roughly 4 event connections, 2 additional FBs and their with. While I know that we have there a problem with a mutex and I would assume for your applications we can find a workaround there I would expect that your execution time will most always be way above 20ms.

However before we fix that I would like to learn more about the problems of the timer infrastructure itself. IMHO you should measure the time that is passing between receiving an START event and after the EO has been sent. By that your calculations would also not interfere so much with the registration at the timer handler.

Could you be so kind and update on your measurement code. I would in parallel think on how we can get the number of mutexes down in the timerhandler. This should definitely improve the situation.

Re: Timer function block accuracy [message #1832610 is a reply to message #1832604]

Mon, 21 September 2020 18:59

Eclipse User

Hi,

Ok, I have made the changes so that timing is between "START" and "EO" of the E_DELAY function block. Please find attached.

Please let me know if I can do anything else to help.

Thank you.

Attachment: E_DELAY.cpp
(Size: 2.69KB, Downloaded 93 times)

Re: Timer function block accuracy [message #1832616 is a reply to message #1832610]

Tue, 22 September 2020 03:27

Eclipse User

I would be really curios how the numbers are now on your embedded system. Are you providing your users the RT event FBs? If not you can get rid of two mutex lock/unlock pairs in funcbloc.cpp. Which should improve execution performance quite a bit and improve also the E_Delay jitter a bit.

[Updated on: Tue, 22 September 2020 03:29] by Moderator

Re: Timer function block accuracy [message #1832622 is a reply to message #1832616]

Tue, 22 September 2020 04:12

Eclipse User

Hi,

Here are the results from the (physical) embedded system. The compiled code includes the changes you provided earlier to timerha.cpp and the updated timing changes in E_DELAY from my last post.

min:0.99ms averr:23.22ms max:46.14ms
min:1.96ms averr:24.67ms max:39.86ms
min:0.03ms averr:237.72ms max:343.72ms
min:1.89ms averr:27.00ms max:59.38ms
min:0.96ms averr:121.44ms max:355.28ms
min:1.09ms averr:17.92ms max:40.53ms
min:2.67ms averr:27.26ms max:60.39ms
min:0.53ms averr:284.45ms max:345.13ms
min:2.21ms averr:22.22ms max:53.46ms
min:2.03ms averr:120.08ms max:314.23ms
min:1.04ms averr:32.84ms max:51.41ms
min:0.32ms averr:16.96ms max:34.76ms
min:0.41ms averr:252.29ms max:300.37ms
min:3.11ms averr:17.58ms max:34.40ms
min:1.85ms averr:140.33ms max:318.92ms
min:2.46ms averr:12.97ms max:39.86ms
min:6.83ms averr:28.80ms max:46.76ms
min:1.78ms averr:284.85ms max:333.26ms
min:3.08ms averr:22.14ms max:42.40ms
min:0.26ms averr:152.31ms max:362.97ms
min:3.29ms averr:18.73ms max:58.57ms
min:0.03ms averr:27.11ms max:58.55ms
min:3.09ms averr:286.66ms max:312.29ms
min:0.59ms averr:21.07ms max:38.96ms
min:0.47ms averr:170.15ms max:331.04ms

We are currently not providing users the RT event FBs. In the following test, the compiled code includes the changes you provided earlier to timerha.cpp, the updated timing changes in E_DELAY from my last post and the two CCriticalRegion's commented out from funcbloc.cpp. Here are the results from the (physical) embedded system.

min:1.96ms averr:16.47ms max:39.83ms
min:1.12ms averr:270.31ms max:325.39ms
min:0.01ms averr:14.98ms max:29.98ms
min:0.37ms averr:122.55ms max:336.92ms
min:0.00ms averr:12.12ms max:30.32ms
min:0.50ms averr:27.09ms max:44.49ms
min:3.90ms averr:277.12ms max:320.00ms
min:1.18ms averr:35.68ms max:50.53ms
min:3.09ms averr:154.85ms max:373.52ms

Please let me know if you would like me to try anything else.

Thank you.

Re: Timer function block accuracy [message #1832854 is a reply to message #1832622]

Sun, 27 September 2020 14:31

Eclipse User

I've been thinking a bit longer on that topic and while there is a little bit of improvement possible in timerhandler I think another measurement would be good to have more feedback on the problem. A crucial point on the delays that you are measuring is the delay that happens between mSuspendSempahore.inc() in resumeSelfSuspand() and that the method selfSuspend() is left. You can find both methods in ecet.h. This would be the time that elapses from the timerhandler informs the thread and the thread awakens. I fear that this could the core of the delays that you are seeing and therefore it would be great to have it measured.

What is important to note so that you are not skewing your measurements. During measuring you must not communicate with your 4diac FORTE devices especially you should not monitor anything.

Re: Timer function block accuracy [message #1834783 is a reply to message #1832854]

Tue, 17 November 2020 14:39

Eclipse User

Today I finally found some time to think about your issue and I have now two improvements that I definitly want to implement for the next 4diac FORTE version. I created the following Bugzilla entry to track that: https://bugs.eclipse.org/bugs/show_bug.cgi?id=568902

[Updated on: Tue, 17 November 2020 14:47] by Moderator

Previous Topic:	ladder language vs forte
Next Topic:	4DIAC 1.13.0 IDE

Goto Forum:

-=] Back to Top [=-

Current Time: Sat Jul 19 18:57:41 EDT 2025

.:: Contact :: Home ::.

Breadcrumbs

Sign up to our Newsletter