ISR, semFlush & semTake - VxWorks

This is a discussion on ISR, semFlush & semTake - VxWorks ; Hi, I am chasing a strange behavior I am seeing on a system that I am working on. We are using Tornado 2.0 VxWorks 5.4 on a MVME162 with MC68040LC. We have a task that waits for binary semaphore (semTake(WAIT_FOREVER)) ...

+ Reply to Thread
Results 1 to 9 of 9

Thread: ISR, semFlush & semTake

  1. ISR, semFlush & semTake

    Hi,
    I am chasing a strange behavior I am seeing on a system that I am
    working on.
    We are using Tornado 2.0 VxWorks 5.4 on a MVME162 with MC68040LC.

    We have a task that waits for binary semaphore (semTake(WAIT_FOREVER))
    that is released by an ISR. Some times it looks like the task does not
    see that the semaphore was given, using semFlush, by the ISR.

    We have 2 counters: first counter is inside the ISR and incremented
    every time the interrupt is serviced. The second counter gets
    incremented every time the task is executed. Initially the counters are
    identical, but overtime the counter inside the task falls behind.

    I am sure about these things:
    * The task has a priority of 3.
    * The interrupt is happening at the right time and with the right
    frequency every 52 ms.
    * The task takes only about 700 us second to complete and go back and
    waits on semTake.
    * The clock rate is set to 500.

    What could be causing this behavior?

    Thanks for your help.

    Ben


  2. Re: ISR, semFlush & semTake

    Is your ISR using semFlush() instead of semGive()? The call to
    semFlush() unblocks all pending tasks, but doesn't change the state of
    the semaphore. If that's the case, your ISR and app task aren't synched
    up at all.


  3. Re: ISR, semFlush & semTake

    Thanks for you reply.

    The ISR is using semFlush. In theory semFlush unlocks all tasks pending
    on a given semaphore. Since I am using a binary semaphore, semGive does
    the same except it is one to one relation.

    Also I replaced semFlush with semGive but the behavior is still the
    same.

    The other thing I forgot to mention: the semaphore is missed only by no
    more than one every miss.

    Thanks,

    Ben


  4. Re: ISR, semFlush & semTake

    The logical conclusion then, is that the task (even at priority 3) is
    getting pre-empted and is (sometimes) taking more than 52 ms to
    complete its work. How about getting a WindView snapshot and looking at
    the context switches? That should tell you what is pre-empting your
    task. There are WV sem flags as well that can show you where in time
    the semaphores get given/taken.


  5. Re: ISR, semFlush & semTake

    Thanks for your help.

    I couldn't use Windview but I used the taskSwitchHookAdd function to
    measure the time taken by tasks and I notice something strange which is
    causing more confusion.

    Mytask, which is missing the semFlush, announced at 3445588083 us,
    using logMsg, that it missed a semTake since 52 ticks elapsed since
    last time it took the semaphore.

    As I mentioned before the clock rate is set to 500 ticks/sec. 52 ticks
    is 2 * 26 ticks. 26 ticks being the frequency of my interrupt.

    0x2d1224 (myTask): 52 -- 3445588083

    a dump of the switchHook log looks like this:
    tNetTask -- 27494 -- 3445223503
    myTask -- 172512 -- 3445396015
    tNetTask -- 35819 -- 3445431834
    myTask -- 44176 -- 3445476010
    tNetTask -- 7908 -- 3445483918
    myTask -- 104242 -- 3445588160 <<<<<<<<<
    tLogTask -- 694 -- 3445588854
    myTask -- 7162 -- 3445596016
    tNetTask -- 44155 -- 3445640171
    myTask -- 155842 -- 3445796013

    The line marked by "<<<<<<<<<<" is when myTask announced it missed a
    semTake.
    It is very stange because it has been running for the last 104242 us
    and I can't see how could it miss the semTake!!

    I keep thinking it got to be something very simple but I can not get to
    it!

    Thanks again.

    Ben

    Fred Medlin wrote:
    > The logical conclusion then, is that the task (even at priority 3) is
    > getting pre-empted and is (sometimes) taking more than 52 ms to
    > complete its work. How about getting a WindView snapshot and looking at
    > the context switches? That should tell you what is pre-empting your
    > task. There are WV sem flags as well that can show you where in time
    > the semaphores get given/taken.



  6. Re: ISR, semFlush & semTake

    hichembf@gmail.com wrote:



    >I keep thinking it got to be something very simple but I can not get to
    >it!


    One thing to check is that you are testing the return value of each and
    every API called for the error condition and the value of errno if the
    error condition is indicated.

    --
    ================================================== ======================
    Michael Kesti | "And like, one and one don't make
    | two, one and one make one."
    mrkesti at comcast dot net | - The Who, Bargain

  7. Re: ISR, semFlush & semTake

    The return values of the API calls are fine, no error reported.
    Is there a way to attach a function, similar to taskSwitchHookAdd, and
    trigger on a semFlush operation?

    Thanks,

    Ben


  8. Re: ISR, semFlush & semTake

    weird...


  9. Re: ISR, semFlush & semTake

    I've been doing more debugging and it is getting me more and more
    confused.
    The strange thing is that this behavior is occurring when the system is
    idle.
    I reduced my system to the very minimum and I used the
    taskSwitchHookAdd function to take precise timing. See below. I added
    an idle task with priority 255 to capture when the system idle.

    The cmpTime is the task waiting for the semaphore released by and ISR
    every 52 ms. WalshTask is doing the same.
    I am 100% sure that the interrupt did occur.

    Snap shot of the tasks and priorities:

    tExcTask _excTask 3e8a54 0
    tLogTask _logTask 3e612c 0
    tRlogind _rlogind 37de24 2
    tTelnetd _telnetd 37bf54 2
    cmpTime _cmpTime 2d2af0 4
    WalshTask _WalshTask 2af5c0 5
    tShell _shell 34eae8 10
    tNetTask _netTask 3a8140 50
    tFtpdTask 47994 37948c 55
    tTftpdTask _tftpdTask 3762c0 55
    tMountd _mountd 37308c 55
    tNfsd _nfsd 3706d4 55
    tNfsd3 _nfsdRequest 36dd1c 60
    tNfsd2 _nfsdRequest 36b364 60
    tNfsd1 _nfsdRequest 3689ac 60
    tNfsd0 _nfsdRequest 365ff4 60
    NtpClient _ntpTask 2d0070 60
    tPortmapd _portmapd 37aa14 100
    idleTask _IdleTask 2d15b0 255

    Timing Log for the taskSwitchHook (Times are in us)

    Taksname -- CPU utilization -- switch time
    ---------------------------------------
    idleTask -- 51699 -- 36415857
    cmpTime -- 394 -- 36416251
    WalshTask -- 79 -- 36416330
    idleTask -- 9943 -- 36426273
    tNetTask -- 144 -- 36426417
    idleTask -- 41535 -- 36467952
    cmpTime -- 399 -- 36468351
    WalshTask -- 35 -- 36468386
    idleTask -- 27921 -- 36496307
    tNetTask -- 142 -- 36496449
    idleTask -- 23586 -- 36520035
    cmpTime -- 396 -- 36520431
    WalshTask -- 35 -- 36520466
    idleTask -- 51646 -- 36572112
    cmpTime -- 378 -- 36572490
    WalshTask -- 30 -- 36572520
    idleTask -- 51692 -- 36624212
    cmpTime -- 374 -- 36624586
    WalshTask -- 32 -- 36624618
    idleTask -- 1664 -- 36626282
    tNetTask -- 139 -- 36626421
    idleTask -- 88259 -- 36714680 <<<<< THIS SHOULD NOT HAPPEN >>>>>>>>
    tNetTask -- 233 -- 36714913
    idleTask -- 13453 -- 36728366
    cmpTime -- 81 -- 36728447 <<<<<<<< Failure announced ....

    Thanks for the help,

    Ben


+ Reply to Thread