To LUGNET HomepageTo LUGNET News HomepageTo LUGNET Guide Homepage
 Help on Searching
 
Post new message to lugnet.robotics.rcx.legosOpen lugnet.robotics.rcx.legos in your NNTP NewsreaderTo LUGNET News Traffic PageSign In (Members)
 Robotics / RCX / legOS / 3078
3077  |  3079
Subject: 
Interesting BrickOS Timing Results
Newsgroups: 
lugnet.robotics.rcx.legos
Date: 
Tue, 14 Jan 2003 03:38:07 GMT
Viewed: 
2988 times
  
Hi All,

The recent posts about interfacing an i2c device to an RCX
sensor port (in .robotics) got me interested in looking at the
kernel code that handles the sensors.

So, I did and found myself looking at the ds_handler function.
This function is the ISR that handles the A/D conversion
interrupt.  Basicly, the routine does something like this:

1. Restore power to previous sensor (if sensor is active)
2. Handle rotation sensor (if present)
3. Handle mux sensor (if present)
4. Skip to next sensor (or battery voltage input)
5. Cut power to sensor (if active)
6. Perform delay loop so sensor value can settle (6 us)
7. Start next A/D conversion

The handler repeats this endlessly.  After digesting this for
a little while, I realized this function was being called a *lot*.
So, I hooked my scope to one of the sensor ports and
configured it as an active sensor.  I found that to convert
4 channels (3 sensors and the battery voltage) it only took
150us.  IOW, it's sampling every A/D channel 6700
times a second (as compared to the standard firmware's
333Hz sample rate).  Ok, cool, I thought, but that's gotta
suck a lot of CPU...  And, it does, as I soon found out.

I wrote a program to measure the amount of available
CPU under a variety of circumstances.  Basicly, the
program figures out how long it takes to execute
a calibrated delay loop.  CPU used by interrupt
service routines and other tasks causes the delay loop
to take longer than if 100% CPU were available.
For example, if it takes 1.5 seconds to execute a 1
second delay loop, then the available CPU would be
(1/1.5) or 67%.

So... I ran the program and it tells me I'm only getting
31% of the CPU.  That's with nothing other than my delay
loop running.  If I turn off the A/D interrupt, I then get
93%.

IOW, the A/D conversion is using about 2/3 of the
available CPU!

Note:  If I turn off all the IRQs (except for the NMI
which is used by the watchdog timer to update the
sys_time variable), I get an available CPU of 101%.
Sounds hokey, and it is, but that's because the
watchdog timer is running 2% slow - but that's the
subject for another post.  ;-)  I adjusted the above
percentages accordingly.

If I configure the inputs for two rotation sensors,
then available CPU goes down to 22%.

Anyways, I thought I would pass these results along
since they are interesting (I was a little astonished).
I have some additional comments, but I'll save them
for later...  This post is a bit long as it is.

LMKWYT,

Mark

P.S.  Here's the program:

/* cpu.c - BrickOS CPU Usage - 1/13/2003 - Mark Riley */

#include <unistd.h>
#include <conio.h>
#include <time.h>
#include <dsensor.h>

// Calibrated delay loop (in milliseconds)

// Explanation: The number of states per instruction is given
// in the comment field.  The state counts assume instruction
// and stack memory fetches are in external RAM.  Each
// iteration of the outer loop takes 16000 states which
// is one millisecond (the RCX cpu clock is 16MHz).

extern void delay_ms(int ms);
__asm__("
.text
.align 1
_delay_ms:
  ; subtract 3 for function call overhead (approximate)
  mov #664-3,r1  ;12

1:
  subs #1,r1     ;6
  mov r1,r1      ;6
  bne 1b         ;12

  ; delay to make outer loop exactly 16000 states
  jmp 2f         ;14
2:
  jmp 2f         ;14
2:

  mov #664,r1    ;12

  subs #1,r0     ;6
  mov r0,r0      ;6
  bne 1b         ;12

  rts            ;20
");

// displays cpu % available
void cpu()
  {
  time_t t0, t;

  t0 = sys_time;
  delay_ms(1000);
  t = sys_time;

  lcd_int(100L * 1000L / (t - t0));
  }

int main(int argc, char **argv)
  {
  while (1)
    {
    // how much cpu you normally get (32%)
    cputs("idle"); msleep(100);
    cpu();
    sleep(3);

    // with two rotation sensors enabled (23%)
    cputs("2rot"); msleep(100);
    ds_rotation_on(&SENSOR_1);
    ds_rotation_on(&SENSOR_2);
    cpu();
    sleep(3);

    // with A/D interrupts disabled (95%)
    cputs("noAd"); msleep(100);
    bit_clear(&AD_CSR, 6);
    cpu();
    bit_set(&AD_CSR, 6);
    sleep(3);

    // with all IRQs but NMI disabled (101% ;-)
    cputs("nIrq"); msleep(100);
    __asm__ __volatile__("\torc  #0x80,ccr\n":::"cc");
    cpu();
    __asm__ __volatile__("\tandc #0x7f,ccr\n":::"cc");
    sleep(3);
    }

  return 0;
  }

/* EOF */



Message has 2 Replies:
  Re: Interesting BrickOS Timing Results
 
Oops, found a little bug. ;-) Forgot to turn off the rotation sensors. Caused a wrong reading if you let the program run through the readings more than once. The rotation sensor section should read like this: // with two rotation sensors enabled (...) (21 years ago, 14-Jan-03, to lugnet.robotics.rcx.legos)
  Re: Interesting BrickOS Timing Results
 
This was a terrific analysis. It's not surprizing that current implementation hogs so much CPU time. If all four A/D channels are scanned every 150 us then the A/D interrupt is occuring every 37.5 us since each A/D channel generates its own (...) (21 years ago, 14-Jan-03, to lugnet.robotics.rcx.legos)

19 Messages in This Thread:






Entire Thread on One Page:
Nested:  All | Brief | Compact | Dots
Linear:  All | Brief | Compact
    

Custom Search

©2005 LUGNET. All rights reserved. - hosted by steinbruch.info GbR