RTEMS tasks timesliced instead of running to completion. TIMESLICE flag is not active!

Fri May 1 10:11:07 UTC 2020

> We can test this with Fernando, by changing the code to avoid printing - 
and instead 
> add integer values in a log buffer... and dump all the log at the end. 

CONFIRMED.

Did a quick check, commenting out the printfs and changing the code to do 
this instead:

void task_begin(int task_no)
{
    logBuffer[logBufferIdx++] = 64+task_no;
}

void task_end(int task_no)
{
    logBuffer[logBufferIdx++] = 128+task_no;
    rtems_event_send(g_init_task_id, RTEMS_EVENT_0 << task_no);
    rtems_task_delete(RTEMS_SELF);
}

..then if we dump the contents of the buffer at the end, the proper - in 
sequence - output is indeed shown, as expected:

Log: 64     <- TASK1 starts
Log: 128   <- TASK1 ends
Log: 65    <- TASK2 starts
Log: 129    <- TASK2 ends
Log: 66   .... etc.
Log: 130
Log: 67
Log: 131

If I uncomment the printfs, and re-introduce them...

Log: 64     <- TASK1 starts
Log: 65     <- TASK2 starts
Log: 66     <- TASK3 starts
Log: 67     <- TASK4 starts
Log: 128     <- TASK1 ends
Log: 129     <- TASK2 ends
Log: 131
Log: 130

That settles it.

Thank you Thomas and Chris - mystery solved.
And lesson learned - console output is pre-emption point with some BSPs 
(ZynQ), but not with others (GR712RC, GR740).

Thanassis Tsiodras
Real-time Embedded Software Engineer 
System, Software and Technology Department

ESTEC
Keplerlaan 1, PO Box 299
NL-2200 AG Noordwijk, The Netherlands
Thanassis.Tsiodras at esa.int | www.esa.int
T +31 71 565 5332

From:   "Thanassis Tsiodras (external)" <Thanassis.Tsiodras at esa.int>
To:     "Thomas Doerfler" <Thomas.Doerfler at imd-systems.de>
Cc:     users at rtems.org
Date:   01/05/2020 11:22
Subject:        Re: RTEMS tasks timesliced instead of running to 
completion. TIMESLICE flag is not active!
Sent by:        "users" <users-bounces at rtems.org>

> When the console driver works in interrupt mode and the output ring 
> buffer between the driver's base context and interrupt context is 
> filled, the driver's base context (and actually the calling task) waits 
> (*******and gets suspended)*************** until there is space again in 
the output buffer. 

I think that is a key observation Thomas - thank you. 

If I understand you well, you are saying that in BSPs that don't use 
polling-based console output, there is a pre-emption point just because of 
a printf. 
That would indeed explain why the moment Task1 prints "Starting" the task 
can get suspended because of this call - and presumably allowing Task2 to 
start, thus giving "timeslice" behavior. 

We can test this with Fernando, by changing the code to avoid printing - 
and instead add integer values in a log buffer... and dump all the log at 
the end. 
If we see that the values are generated in the proper sequence, then it is 
indeed the console output that causes this pre-emption. 

Does anyone know if the ZynQ's BSP uses a small enough console buffer that 
would be filled up with just printing "[TASK 0] Starting..." - and thus 
cause a pre-emption? 

Thanassis Tsiodras 
Real-time Embedded Software Engineer 
System, Software and Technology Department 

ESTEC 
Keplerlaan 1, PO Box 299 
NL-2200 AG Noordwijk, The Netherlands 
Thanassis.Tsiodras at esa.int | www.esa.int 
T +31 71 565 5332 

From:        "Thomas Doerfler" <Thomas.Doerfler at imd-systems.de> 
To:        users at rtems.org 
Date:        01/05/2020 10:54 
Subject:        Re: RTEMS tasks timesliced instead of running to 
completion. TIMESLICE flag is not active! 
Sent by:        "users" <users-bounces at rtems.org> 

Am 01.05.20 um 10:13 schrieb Thanassis Tsiodras (external):
> /> Polled vs interrupt console drivers?/
> 
> I don't see how...  With tasks spawned with RTEMS_DEFAULT_MODES and
> CONFIGURE_MAXIMUM_PROCESSORS set to 1, Task 2 should not be allowed to
> run until Task 1 completes - so the output of "Starting" ( in
> "task_begin" of Task 2) should not be able to precede the output of
> "Computed" at the end of Task1 - the relevant print should not have
> happened yet.

When the console driver works in interrupt mode and the output ring
buffer between the driver's base context and interrupt context is
filled, the driver's base context (and actually the calling task) waits
(and gets suspended) until there is space again in the output buffer.

So this is a point where the next task may start to execute.

Remember: doing I/O operations may often preempt a running task,
depending on the driver structure.

IMHO, relying on "NO_PREEMPT" as a way to avoid other tasks to run is
dangerous.

OTOH, I would expect more mingled output if this were the real cause for
the behavior seen. So there me a different cause for this.

wkr,

Thomas.

> 
> I can understand how console output can become garbled in tasks that are
> running concurrently - but in this case, I would expect them to run in
> sequence.
> The only way for this
> 
> [TASK 0] Starting...
> [TASK 0] Computed the correct floating point result.
> [TASK 1] Starting...
> [TASK 1] Computed the correct integer result.
> [TASK 2] Starting...
> [TASK 2] Computed the correct floating point result.
> [TASK 3] Starting...
> [TASK 3] Computed the correct integer result.
> 
> to turn into this
> 
> The expected result:
> [TASK 0] Starting...
> [TASK 1] Starting...
> [TASK 2] Starting...
> [TASK 3] Starting...
> [TASK 0] Computed the correct floating point result.
> [TASK 1] Computed the correct integer result.
> [TASK 2] Computed the correct floating point result.
> [TASK 3] Computed the correct integer result.
> 
> ...is if indeed, the tasks are running concurrently with the ZynQ BSP.
> 
> So the question is:
> 
> Given the task spawning parameters ("RTEMS_DEFAULT_MODES") and
> CONFIGURE_MAXIMUM_PROCESSORS set to 1, is it right to experience
> timeslicing on the ZynQ ZC706?
> 
> *Thanassis Tsiodras*
> Real-time Embedded Software Engineer
> System, Software and Technology Department
> 
> *ESTEC*
> Keplerlaan 1, PO Box 299
> NL-2200 AG Noordwijk, The Netherlands
> Thanassis.Tsiodras at esa.int | www.esa.int
> T +31 71 565 5332
> 
> 
> 
> From:        "Chris Johns" <chrisj at rtems.org>
> To:        "Thanassis Tsiodras (external)" <Thanassis.Tsiodras at esa.int>
> Cc:        "Gedare Bloom" <gedare at rtems.org>, "rtems-users at rtems.org"
> <users at rtems.org>, "Fernando Domínguez Pousa" <fdpousa at gmv.com>
> Date:        01/05/2020 09:46
> Subject:        Re: RTEMS tasks timesliced instead of running to
> completion. TIMESLICE flag is not active!
> ------------------------------------------------------------------------
> 
> 
> 
> On 1/5/20 5:08 pm, Thanassis Tsiodras (external) wrote:
>> Note that this test (complete code in 
>> 
https://gitrepos.estec.esa.int/ttsiodras/RTEMS-build-workflows/-/tree/master/OAR
)
> 
>> creates the proper - non-interleaved - output when compiled and 
executed
>> for the GR712RC and GR740 boards... but creates the interleaved output
>> in a ZynQ ZC706 board.
> 
> Polled vs interrupt console drivers?
> 
> Chris
> 
> 
> 
> This message is intended only for the recipient(s) named above. It may 
contain proprietary information and/or
> protected content. Any unauthorised disclosure, use, retention or 
dissemination is prohibited. If you have received
> this e-mail in error, please notify the sender immediately. ESA applies 
appropriate organisational measures to protect
> personal data, in case of data privacy queries, please contact the ESA 
Data Protection Officer (dpo at esa.int).
> 
> 
> _______________________________________________
> users mailing list
> users at rtems.org
> http://lists.rtems.org/mailman/listinfo/users
> 

-- 
IMD Ingenieurbuero fuer Microcomputertechnik
Thomas Doerfler           Herbststrasse 8
D-82178 Puchheim          Germany
email:    Thomas.Doerfler at imd-systems.de
PGP public key available on request
_______________________________________________
users mailing list
users at rtems.org
http://lists.rtems.org/mailman/listinfo/users

This message is intended only for the recipient(s) named above. It may 
contain proprietary information and/or
protected content. Any unauthorised disclosure, use, retention or 
dissemination is prohibited. If you have received
this e-mail in error, please notify the sender immediately. ESA applies 
appropriate organisational measures to protect
personal data, in case of data privacy queries, please contact the ESA 
Data Protection Officer (dpo at esa.int).

_______________________________________________
users mailing list
users at rtems.org
http://lists.rtems.org/mailman/listinfo/users

This message is intended only for the recipient(s) named above. It may contain proprietary information and/or
protected content. Any unauthorised disclosure, use, retention or dissemination is prohibited. If you have received
this e-mail in error, please notify the sender immediately. ESA applies appropriate organisational measures to protect
personal data, in case of data privacy queries, please contact the ESA Data Protection Officer (dpo at esa.int).

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rtems.org/pipermail/users/attachments/20200501/2eb2d688/attachment-0001.html>