Erratic interrupt latency

Ken_Schumm1 · March 9, 2001, 5:18pm

We’re having some trouble getting consistent interrupt latency on
a QNX 4.25 embedded PC/104 product of ours. Usually the latency is
around 10-15 us as measured on a dso. Sometimes, though, maybe
…001% of the time, this latency stretches out to as much as 120 us.
We need a reliable 4 kHz collection rate, so these 120 us
disturbances often cause data to be lost.

Our product is based around an Ampro 4DXi board (486/133), with an
Ampro MiniModule/LCD II vga card and a custom data acquisition card
of our own design.

I think we have eliminated photon and the graphics subsystem
from consideration. We removed the video card and ran the system
without photon and our gui software with no improvement.

We thought perhaps that the cpu was being put into low power mode
by the idle process, so we wrote our own idle, that spins at
priority one. This made no difference.

Our data collection process is running at priority 29, and proc
at 28. We have rotated the data collection interrupt, using the
-i 7 option to proc, to make it the highest priority interrupt
in the box. We tried both -zn and -zN options to proc to no
avail.

We have also tried killing off most everything except the
main data collection process (supervisor) and this made no
difference.

Ideas are appreciated, sin info is below.

--------------------- sin ------------------------------------
SID PID PROGRAM PRI STATE BLK CODE DATA
– – Microkernel — ----- — 10448 0
0 1 sys/Proc32 28f READY — 118k 811k
0 2 sys/Slib32 10r RECV 0 53k 4096
0 4 /bin/Fsys 10r RECV 0 77k 409k
0 5 usr/local/tffs/Fsys.doc 10r RECV 0 36k 53k
0 8 /bin/Dev32 24f RECV 0 32k 90k
0 9 /bin/Dev32.ansi 20r RECV 0 40k 49k
0 10 idle 0r READY — 0 0
0 19 //2/bin/nameloc 20o RECV 0 6144 20k
0 20 //2/bin/nameloc 20o REPLY 0 6144 16k
0 24 //2/minya/bin/speaker 10o RECV 0 4096 12k
0 27 //2/minya/bin/dbmgr 10o RECV 0 20k 28k
0 28 //2//bin/supervisor 29f RECV 0 53k 24k
0 35 //2//photon/bin/Photon 10r READY — 57k 28k
0 37 //2//vesabios.ms 10o RECV 0 40k 28k
0 39 //2//drivers/Pg.vga4 12r REPLY 35 118k 118k
0 42 //2//bin/phfontall 10r RECV 0 159k 442k
0 50 //2//bin/Input.mdi8000 12o RECV 0 26k 28k
0 51 //2/minya/bin/gui 10o READY — 122k 114k
0 54 //2/*/bin/Input.mdi8000 10o RECV 0 26k 28k
0 58 //2/bin/Dev32.ser 20r RECV 0 16k 32k
0 64 //2/bin/tinit 10o WAIT -1 16k 28k
0 66 //2/minya/bin/hostif 10o REPLY 8 57k 32k
0 70 //2/bin/dumper 28o RECV 0 16k 20k
1 71 //2/bin/login 10o REPLY 8 24k 20k
2 72 //2/bin/sh 10o WAIT -1 94k 45k
2 84 //2/bin/sin 10o REPLY 1 45k 49k

-------------------- sin ver ---------------------------------
PROGRAM NAME VERSION DATE
sys/Proc32 Proc 4.25I Nov 25 1998
sys/Proc32 Slib16 4.23G Oct 04 1996
sys/Slib32 Slib32 4.24B Aug 12 1997
/bin/Fsys Fsys32 4.24S Jul 16 1998
/bin/Fsys Floppy 4.24B Aug 19 1997
/bin/Fsys.aha7scsi scsi 4.24M Mar 23 1998
//1/bin/Dev32 Dev32 4.23G Oct 04 1996
//1/bin/Dev32.ansi Dev32.ansi 4.23H Nov 21 1996
//1/bin/Dev32.ser Dev32.ser 4.23I Jun 27 1997
//1/bin/Dev32.par Dev32.par 4.23G Oct 04 1996
//1/bin/Dev32.pty Dev32.pty 4.23G Oct 04 1996
//1/bin/Mouse Mouse 4.24A Aug 22 1997
//1/bin/Iso9660fsys Iso9660fsys 4.23B Jun 10 1998
//1/bin/Pipe Pipe 4.23A Feb 26 1996
//1/bin/Net Net 4.25B Jul 27 1998
//1/bin/Net.ether1000 Net.ether100 4.24B Jul 24 1998
//1/usr/bin/lpsrvr lpsrvr 4.24A Jun 26 1997
//1//bin/phfontpfr Photon Font 1.13A Jul 07 1998
//1//usr/ucb/Socklet Socklet 4.25G Dec 08 1998
//1//photon/bin/Photon Photon 1.13D Sep 03 1998
//1//4.25/usr/ucb/Dns Dns 1.00C Jun 30 1998

------------------ sin info -----------------------------------
Node CPU Machine Speed Memory Ticksize Display Flags
2 486/487 AT 9708 4161k/7962k 10.0ms VGA Color -3-±---------8P

Heapp Heapf Heapl Heapn Hands Names Sessions Procs Timers Nodes Virtual
0 0 23256 0 64 100 64 500 125 4 6M/ 25M

Boot from Hard at — – --:-- Locators: 2

------------------ sin irq ------------------------------------
IRQ PID PROGRAM CS:IP DS
-1 8 /bin/Dev32 0005:005760 000D
-1 9 /bin/Dev32.ansi 0005:005DC0 000D
-1 58 //2/bin/Dev32.ser 0005:0024FC 000D
0 1 sys/Proc32 00F0:004CB3 00F8
1 9 /bin/Dev32.ansi 0005:00690C 000D
3 58 //2/bin/Dev32.ser 0005:00177C 000D
4 58 //2/bin/Dev32.ser 0005:0017A4 000D
7 28 //2/*/bin/supervisor 0005:00AE70 000D
13 1 sys/Proc32 00F0:004C77 00F8

Rennie_Allen2 · March 9, 2001, 6:40pm

Wild a**ed guess… you might want to remove Dev.ansi. It can
cause large latencies (typically only during console switches
though). IIRC the latency is on the order of 100usec.

-----Original Message-----
From: Ken Schumm [mailto:kwschumm@qsolv.com]
Posted At: Friday, March 09, 2001 9:18 AM
Posted To: qnx4
Conversation: Erratic interrupt latency
Subject: Erratic interrupt latency

--------------------- sin ------------------------------------
SID PID PROGRAM PRI STATE BLK CODE DATA
– – Microkernel — ----- — 10448 0
0 1 sys/Proc32 28f READY — 118k 811k
0 2 sys/Slib32 10r RECV 0 53k 4096
0 4 /bin/Fsys 10r RECV 0 77k 409k
0 5 usr/local/tffs/Fsys.doc 10r RECV 0 36k 53k
0 8 /bin/Dev32 24f RECV 0 32k 90k
0 9 /bin/Dev32.ansi 20r RECV 0 40k 49k

Hugh_Brown1 · March 9, 2001, 7:49pm

Well I must say that that’s pretty good performance from a 486/133!
You don’t mention how you are performing your data collection, but
have you tried the system without the ethernet driver, as the NE2000
is not the best solution if you are looking for performance? Also
Fsys.doc could be causing some delays as well.

Hugh.

Previously, Ken Schumm wrote in qdn.public.qnx4:

We’re having some trouble getting consistent interrupt latency on
a QNX 4.25 embedded PC/104 product of ours. Usually the latency is
around 10-15 us as measured on a dso. Sometimes, though, maybe
.001% of the time, this latency stretches out to as much as 120 us.
We need a reliable 4 kHz collection rate, so these 120 us
disturbances often cause data to be lost.

Our product is based around an Ampro 4DXi board (486/133), with an
Ampro MiniModule/LCD II vga card and a custom data acquisition card
of our own design.

I think we have eliminated photon and the graphics subsystem
from consideration. We removed the video card and ran the system
without photon and our gui software with no improvement.

We thought perhaps that the cpu was being put into low power mode
by the idle process, so we wrote our own idle, that spins at
priority one. This made no difference.

Our data collection process is running at priority 29, and proc
at 28. We have rotated the data collection interrupt, using the
-i 7 option to proc, to make it the highest priority interrupt
in the box. We tried both -zn and -zN options to proc to no
avail.

We have also tried killing off most everything except the
main data collection process (supervisor) and this made no
difference.

Ideas are appreciated, sin info is below.

--------------------- sin ------------------------------------
SID PID PROGRAM PRI STATE BLK CODE DATA
– – Microkernel — ----- — 10448 0
0 1 sys/Proc32 28f READY — 118k 811k
0 2 sys/Slib32 10r RECV 0 53k 4096
0 4 /bin/Fsys 10r RECV 0 77k 409k
0 5 usr/local/tffs/Fsys.doc 10r RECV 0 36k 53k
0 8 /bin/Dev32 24f RECV 0 32k 90k
0 9 /bin/Dev32.ansi 20r RECV 0 40k 49k
0 10 idle 0r READY — 0 0
0 19 //2/bin/nameloc 20o RECV 0 6144 20k
0 20 //2/bin/nameloc 20o REPLY 0 6144 16k
0 24 //2/minya/bin/speaker 10o RECV 0 4096 12k
0 27 //2/minya/bin/dbmgr 10o RECV 0 20k 28k
0 28 //2//bin/supervisor 29f RECV 0 53k 24k
0 35 //2//photon/bin/Photon 10r READY — 57k 28k
0 37 //2//vesabios.ms 10o RECV 0 40k 28k
0 39 //2//drivers/Pg.vga4 12r REPLY 35 118k 118k
0 42 //2//bin/phfontall 10r RECV 0 159k 442k
0 50 //2//bin/Input.mdi8000 12o RECV 0 26k 28k
0 51 //2/minya/bin/gui 10o READY — 122k 114k
0 54 //2/*/bin/Input.mdi8000 10o RECV 0 26k 28k
0 58 //2/bin/Dev32.ser 20r RECV 0 16k 32k
0 64 //2/bin/tinit 10o WAIT -1 16k 28k
0 66 //2/minya/bin/hostif 10o REPLY 8 57k 32k
0 70 //2/bin/dumper 28o RECV 0 16k 20k
1 71 //2/bin/login 10o REPLY 8 24k 20k
2 72 //2/bin/sh 10o WAIT -1 94k 45k
2 84 //2/bin/sin 10o REPLY 1 45k 49k

-------------------- sin ver ---------------------------------
PROGRAM NAME VERSION DATE
sys/Proc32 Proc 4.25I Nov 25 1998
sys/Proc32 Slib16 4.23G Oct 04 1996
sys/Slib32 Slib32 4.24B Aug 12 1997
/bin/Fsys Fsys32 4.24S Jul 16 1998
/bin/Fsys Floppy 4.24B Aug 19 1997
/bin/Fsys.aha7scsi scsi 4.24M Mar 23 1998
//1/bin/Dev32 Dev32 4.23G Oct 04 1996
//1/bin/Dev32.ansi Dev32.ansi 4.23H Nov 21 1996
//1/bin/Dev32.ser Dev32.ser 4.23I Jun 27 1997
//1/bin/Dev32.par Dev32.par 4.23G Oct 04 1996
//1/bin/Dev32.pty Dev32.pty 4.23G Oct 04 1996
//1/bin/Mouse Mouse 4.24A Aug 22 1997
//1/bin/Iso9660fsys Iso9660fsys 4.23B Jun 10 1998
//1/bin/Pipe Pipe 4.23A Feb 26 1996
//1/bin/Net Net 4.25B Jul 27 1998
//1/bin/Net.ether1000 Net.ether100 4.24B Jul 24 1998
//1/usr/bin/lpsrvr lpsrvr 4.24A Jun 26 1997
//1//bin/phfontpfr Photon Font 1.13A Jul 07 1998
//1//usr/ucb/Socklet Socklet 4.25G Dec 08 1998
//1//photon/bin/Photon Photon 1.13D Sep 03 1998
//1//4.25/usr/ucb/Dns Dns 1.00C Jun 30 1998

------------------ sin info -----------------------------------
Node CPU Machine Speed Memory Ticksize Display Flags
2 486/487 AT 9708 4161k/7962k 10.0ms VGA Color -3-±---------8P

Heapp Heapf Heapl Heapn Hands Names Sessions Procs Timers Nodes Virtual
0 0 23256 0 64 100 64 500 125 4 6M/ 25M

Boot from Hard at — – --:-- Locators: 2

------------------ sin irq ------------------------------------
IRQ PID PROGRAM CS:IP DS
-1 8 /bin/Dev32 0005:005760 000D
-1 9 /bin/Dev32.ansi 0005:005DC0 000D
-1 58 //2/bin/Dev32.ser 0005:0024FC 000D
0 1 sys/Proc32 00F0:004CB3 00F8
1 9 /bin/Dev32.ansi 0005:00690C 000D
3 58 //2/bin/Dev32.ser 0005:00177C 000D
4 58 //2/bin/Dev32.ser 0005:0017A4 000D
7 28 //2/*/bin/supervisor 0005:00AE70 000D
13 1 sys/Proc32 00F0:004C77 00F8

\

Alex1 · March 9, 2001, 7:51pm

Hugh Brown wrote:

Well I must say that that’s pretty good performance from a 486/133!
You don’t mention how you are performing your data collection, but
have you tried the system without the ethernet driver, as the NE2000
is not the best solution if you are looking for performance? Also
Fsys.doc could be causing some delays as well.

I would also look at the DOC.
Did you try logging (I assume you are logging to disk) to
a hard disk in stead of the DOC, or a RAM disk?

Ken_Schumm1 · March 9, 2001, 8:15pm

Previously, Hugh Brown wrote in qdn.public.qnx4:

Well I must say that that’s pretty good performance from a 486/133!
You don’t mention how you are performing your data collection, but
have you tried the system without the ethernet driver, as the NE2000
is not the best solution if you are looking for performance? Also
Fsys.doc could be causing some delays as well.

Hugh.

The ethernet card was installed, and Net started, only to take the
‘sin’ snapshots. It is not present in the target system, which is
a handheld non-networked device. All of the time measurements we
observed were without Net running and without the ethernet card
installed.

I also killed off Fsys.doc (it is only used to boot off of), and
it made no difference.

Our interrupt handler is hooked to IRQ 7, which is the highest
priority interrupt (via Proc’s -i7 option). It is about a dozen
lines long. All it does is read four registers from an fpga, stuff
the values in some global variables, and return a proxy. Below
is the interrupt handler. The outp() instructions are present
only to toggle a pin on the serial port which we monitor with
the scope.

// ------------------- cut here -----------------------

#include <stdio.h>
#include <conio.h>
#include <i86.h>
#include <sys/stat.h>
#include <unistd.h>

#include <supervisor.h>

#pragma off (check_stack);

pid_t far AsyncInt( VOID )
{
outp( 0x378, 1 ) ;

/*

Read ISR first, to keep read of dppr from clearing it.
*/

Gbl.isr = Gbl.fpga->isr ;

/*

For “probe data arrived” interrupts, disable the interrupt
until the probe data can be processed. These are reenabled
in hwint.c when a pulse has been completely handled.
*/

if( Gbl.isr & DPI )
{
Gbl.imr &= ~DPIE ; // Disable data packet arrival interrupts
Gbl.fpga->imr = Gbl.imr ; // Make it so
}

Gbl.dpsr = Gbl.fpga->dpsr ;
Gbl.dppr = Gbl.fpga->dppr & 0x3fff ;
Gbl.dptr = Gbl.fpga->dptr ;
Gbl.dpcsr= Gbl.fpga->dpcsr;

Gbl.prrh = Gbl.fpga->prrh & 0x000000ff ;
Gbl.prrl = Gbl.fpga->prrl ;

outp( 0x378, 0 ) ;
return( Gbl.iproxy ) ;

} // end AsyncInt()

#pragma on (check_stack);

// ------------------------- cut here -------------------------

[…]

Ken_Schumm1 · March 9, 2001, 8:18pm

Previously, Alex wrote in qdn.public.qnx4:

Hugh Brown wrote:

Well I must say that that’s pretty good performance from a 486/133!
You don’t mention how you are performing your data collection, but
have you tried the system without the ethernet driver, as the NE2000
is not the best solution if you are looking for performance? Also
Fsys.doc could be causing some delays as well.

I would also look at the DOC.
Did you try logging (I assume you are logging to disk) to
a hard disk in stead of the DOC, or a RAM disk?

We are not logging anything to the DOC. The DOC is only used
to boot. Collected data is summarized for the display, but is
not stored on non-volatile media. Killing off the Fsys.doc
driver did not affect our performance one way or another.

Ken_Schumm1 · March 9, 2001, 8:56pm

Previously, Rennie Allen wrote in qdn.public.qnx4:

Wild a**ed guess… you might want to remove Dev.ansi. It can
cause large latencies (typically only during console switches
though). IIRC the latency is on the order of 100usec.

We’ll give this a try. Nothing writes to the console (all apps
close all fd’s), and nothing does a console switch, so I don’t
expect much, but it’s certainly worth trying.

[…]

Ken_Schumm1 · March 9, 2001, 9:51pm

Nope, slaying Dev.ansi did nothing. I killed off Dev.ansi and Dev.ser
and Fsys.doc and still see see latencies out to 120 us.

AFAIK, the only things that can cause this behavior are

a) something is disabling interrupts
b) the kernel is preempting our stuff
c) an interrupt handler somewhere is taking an awfully long time

Our stuff never disables interrupts. In a stripped down test, the
only interrupts used are irq7 (ours) and 0 and 13 (Proc32).

Does Proc32 occasionally disable interrupts for 100 us or so?

If not, I am concluding that the kernel is to blame. What kernel
function would run for 100 us or so, preempting us?

Previously, Rennie Allen wrote in qdn.public.qnx4:

Wild a**ed guess… you might want to remove Dev.ansi. It can
cause large latencies (typically only during console switches
though). IIRC the latency is on the order of 100usec.

-----Original Message-----
From: Ken Schumm [mailto:> kwschumm@qsolv.com> ]
Posted At: Friday, March 09, 2001 9:18 AM
Posted To: qnx4
Conversation: Erratic interrupt latency
Subject: Erratic interrupt latency

--------------------- sin ------------------------------------
SID PID PROGRAM PRI STATE BLK CODE DATA
– – Microkernel — ----- — 10448 0
0 1 sys/Proc32 28f READY — 118k 811k
0 2 sys/Slib32 10r RECV 0 53k 4096
0 4 /bin/Fsys 10r RECV 0 77k 409k
0 5 usr/local/tffs/Fsys.doc 10r RECV 0 36k 53k
0 8 /bin/Dev32 24f RECV 0 32k 90k
0 9 /bin/Dev32.ansi 20r RECV 0 40k 49k

Rennie_Allen2 · March 10, 2001, 12:29am

I took a closer look at your diagnostic info. I see your attaching to
IRQ 7. This is the glitch handler, I always avoid IRQ 7 like the plague
for rt stuff. That said, I wouldn’t imagine that it would be that bad
(100usec) but it’s worth a shot; I would try changing to a different IRQ
(oh and don’t forget to change the IRQ priorities back so 7 isn’t the
highest).

Rennie_Allen2 · March 10, 2001, 12:31am

Oh, one other possibility. There is always the dreaded System
Management Mode…

-----Original Message-----
From: Rennie Allen
Posted At: Friday, March 09, 2001 4:29 PM
Posted To: qnx4
Conversation: Erratic interrupt latency
Subject:

I took a closer look at your diagnostic info. I see your attaching to
IRQ 7. This is the glitch handler, I always avoid IRQ 7 like the plague
for rt stuff. That said, I wouldn’t imagine that it would be that bad
(100usec) but it’s worth a shot; I would try changing to a different IRQ
(oh and don’t forget to change the IRQ priorities back so 7 isn’t the
highest).

Ian_M_Zagorskih · March 10, 2001, 9:53am

“Rennie Allen” <RAllen@csical.com> wrote in message
news:D4907B331846D31198090050046F80C90319FE@exchangecal.hq.csical.com…

I took a closer look at your diagnostic info. I see your attaching to
IRQ 7. This is the glitch handler, I always avoid IRQ 7 like the plague
for rt stuff. That said, I wouldn’t imagine that it would be that bad
(100usec) but it’s worth a shot; I would try changing to a different IRQ
(oh and don’t forget to change the IRQ priorities back so 7 isn’t the
highest).

why don’t you like so exactly irq 7 ?

// wbr

Arnauld_Disableu · March 10, 2001, 11:27am

“Ken Schumm” <kwschumm@qsolv.com> a écrit dans le message news:
Voyager.010309121542.25825A@dilbert…

Previously, Hugh Brown wrote in qdn.public.qnx4:
Well I must say that that’s pretty good performance from a 486/133!
You don’t mention how you are performing your data collection, but
have you tried the system without the ethernet driver, as the NE2000
is not the best solution if you are looking for performance? Also
Fsys.doc could be causing some delays as well.

Hugh.

The ethernet card was installed, and Net started, only to take the
‘sin’ snapshots. It is not present in the target system, which is
a handheld non-networked device. All of the time measurements we
observed were without Net running and without the ethernet card
installed.

I also killed off Fsys.doc (it is only used to boot off of), and
it made no difference.

Our interrupt handler is hooked to IRQ 7, which is the highest
priority interrupt (via Proc’s -i7 option). It is about a dozen
lines long. All it does is read four registers from an fpga, stuff
the values in some global variables, and return a proxy. Below
is the interrupt handler. The outp() instructions are present
only to toggle a pin on the serial port which we monitor with
the scope.

// ------------------- cut here -----------------------

#include <stdio.h
#include <conio.h
#include <i86.h
#include <sys/stat.h
#include <unistd.h

#include <supervisor.h

#pragma off (check_stack);

pid_t far AsyncInt( VOID )
{
outp( 0x378, 1 ) ;

Usually, this is the parallel port register, usually using IRQ 7 line. Maybe
this remark is stupid, but …

/*

Read ISR first, to keep read of dppr from clearing it.
*/
…

–
Arnauld Disableu
arnauld@disableu.net
http://www.disableu.net

Compatible an 2000
Year 2000 compliant

Ken_Schumm1 · March 10, 2001, 5:35pm

Arnauld Disableu wrote in message <98chh3$7ss$1@inn.qnx.com>…

“Ken Schumm” <> kwschumm@qsolv.com> > a écrit dans le message news:
Voyager.010309121542.25825A@dilbert…
Previously, Hugh Brown wrote in qdn.public.qnx4:
Well I must say that that’s pretty good performance from a 486/133!
[…]

pid_t far AsyncInt( VOID )
{
outp( 0x378, 1 ) ;

Usually, this is the parallel port register, usually using IRQ 7 line.
Maybe
this remark is stupid, but …

Not at all stupid. We are toggling data bit one of the parallel port so we
can monitor it with a scope. We wanted to monitor both interrupt latency
and the duration of the ISR, so we used the parallel port to do it with.
It doesn’t seem to affect our results one way or the other.

[…]

Ken_Schumm1 · March 10, 2001, 9:38pm

Previously, Rennie Allen wrote in qdn.public.qnx4:

I took a closer look at your diagnostic info. I see your attaching to
IRQ 7. This is the glitch handler, I always avoid IRQ 7 like the plague
for rt stuff. That said, I wouldn’t imagine that it would be that bad
(100usec) but it’s worth a shot; I would try changing to a different IRQ
(oh and don’t forget to change the IRQ priorities back so 7 isn’t the
highest).

This was a good idea for something to check. Thanks.

I ran a test for millions of interrupts and the interrupt handler was
never once invoked when IRQ7 in the 8259 ISR register was clear. My
understanding of phantom interrupts is that when they occur they will
generate an interrupt, but the 8259 ISR register will not reflect the
interrupt.

Perhaps the kernel filters these out for IRQ7, but I can’t imagine
that this simple check would take 100+ us.

Ken_Schumm1 · March 10, 2001, 9:41pm

Previously, Ian M. Zagorskih wrote in qdn.public.qnx4:

“Rennie Allen” <> RAllen@csical.com> > wrote in message
news:> D4907B331846D31198090050046F80C90319FE@exchangecal.hq.csical.com> …
I took a closer look at your diagnostic info. I see your attaching to
IRQ 7. This is the glitch handler, I always avoid IRQ 7 like the plague
for rt stuff. That said, I wouldn’t imagine that it would be that bad
(100usec) but it’s worth a shot; I would try changing to a different IRQ
(oh and don’t forget to change the IRQ priorities back so 7 isn’t the
highest).

why don’t you like so exactly irq 7 ?

Basically, when a noise spike on an interrupt line occurs, the
PIC has to report an interrupt number to the processor. IRQ7
(and IRQ15 on the cascade PIC) are the ones that are reported.
So, interrupt line glitches can cause spurious interrupts on IRQ7
and 15. These seem easy to check for and filter out, though.

I would guess that the kernel filters these out, but I don’t
know for sure. QSSL?

Mario_Charest1 · March 11, 2001, 2:21am

“Ken Schumm” <kwschumm@qsolv.com> wrote in message
news:Voyager.010309135116.5017A@dilbert…

Nope, slaying Dev.ansi did nothing. I killed off Dev.ansi and Dev.ser
and Fsys.doc and still see see latencies out to 120 us.

AFAIK, the only things that can cause this behavior are

a) something is disabling interrupts
b) the kernel is preempting our stuff
c) an interrupt handler somewhere is taking an awfully long time

d) hardware that introduces wait states
e) What’s the name for this nasty thing BIOS/hardware do? SPM???

With you DSO can you monitor the bus (the one connected
to the CPU) to see what kind of activity is going on.

If you can get/buy/rent a fancy scope that you can connect
the whole cpu to, to see EXACLTY what is happening.
It can’t get better then that. I use that think once to
write/debug an IPL, surely beats the hell out of debugging
through led

Donald_Backstrom1 · March 12, 2001, 12:29am

Have you tried running your stuff above the kernel priority? You need to
send an option to Proc I think to run it at a lower priority, then boost
your stuff above it. That will mean you are never pre-empted by proc and
you should get a better idea when interrupts are enabled/disabled.

Mario Charest wrote:

“Ken Schumm” <> kwschumm@qsolv.com> > wrote in message
news:Voyager.010309135116.5017A@dilbert…
Nope, slaying Dev.ansi did nothing. I killed off Dev.ansi and Dev.ser
and Fsys.doc and still see see latencies out to 120 us.

AFAIK, the only things that can cause this behavior are

a) something is disabling interrupts
b) the kernel is preempting our stuff
c) an interrupt handler somewhere is taking an awfully long time

d) hardware that introduces wait states
e) What’s the name for this nasty thing BIOS/hardware do? SPM???

With you DSO can you monitor the bus (the one connected
to the CPU) to see what kind of activity is going on.

If you can get/buy/rent a fancy scope that you can connect
the whole cpu to, to see EXACLTY what is happening.
It can’t get better then that. I use that think once to
write/debug an IPL, surely beats the hell out of debugging
through led >

Ken_Schumm1 · March 12, 2001, 12:50am

Previously, Donald Backstrom wrote in qdn.public.qnx4:

Have you tried running your stuff above the kernel priority? You need to
send an option to Proc I think to run it at a lower priority, then boost
your stuff above it. That will mean you are never pre-empted by proc and
you should get a better idea when interrupts are enabled/disabled.

I don’t think I can run our stuff at a higher priority than the kernel.
I can run it at a higher priority than Proc, which I am already doing.
Proc is at 28f, our stuff is at 29f.

[…]

Armin_Steinhoff1 · March 12, 2001, 12:11pm

Hi Ken,

could it be that the handler of the SMI (System Management
Interrupt) does a lot at your machine?
This happens if you have enabled a lot of e.g. power
management actions on the board.

The SMI handler is located in the BIOS … I would try
to minimize all power management and similar activities.

Armin

Ken Schumm wrote:

We’re having some trouble getting consistent interrupt latency on
a QNX 4.25 embedded PC/104 product of ours. Usually the latency is
around 10-15 us as measured on a dso. Sometimes, though, maybe
.001% of the time, this latency stretches out to as much as 120 us.
We need a reliable 4 kHz collection rate, so these 120 us
disturbances often cause data to be lost.

Our product is based around an Ampro 4DXi board (486/133), with an
Ampro MiniModule/LCD II vga card and a custom data acquisition card
of our own design.

I think we have eliminated photon and the graphics subsystem
from consideration. We removed the video card and ran the system
without photon and our gui software with no improvement.

We thought perhaps that the cpu was being put into low power mode
by the idle process, so we wrote our own idle, that spins at
priority one. This made no difference.

Our data collection process is running at priority 29, and proc
at 28. We have rotated the data collection interrupt, using the
-i 7 option to proc, to make it the highest priority interrupt
in the box. We tried both -zn and -zN options to proc to no
avail.

We have also tried killing off most everything except the
main data collection process (supervisor) and this made no
difference.

Ideas are appreciated, sin info is below.

--------------------- sin ------------------------------------
SID PID PROGRAM PRI STATE BLK CODE DATA
– – Microkernel — ----- — 10448 0
0 1 sys/Proc32 28f READY — 118k 811k
0 2 sys/Slib32 10r RECV 0 53k 4096
0 4 /bin/Fsys 10r RECV 0 77k 409k
0 5 usr/local/tffs/Fsys.doc 10r RECV 0 36k 53k
0 8 /bin/Dev32 24f RECV 0 32k 90k
0 9 /bin/Dev32.ansi 20r RECV 0 40k 49k
0 10 idle 0r READY — 0 0
0 19 //2/bin/nameloc 20o RECV 0 6144 20k
0 20 //2/bin/nameloc 20o REPLY 0 6144 16k
0 24 //2/minya/bin/speaker 10o RECV 0 4096 12k
0 27 //2/minya/bin/dbmgr 10o RECV 0 20k 28k
0 28 //2//bin/supervisor 29f RECV 0 53k 24k
0 35 //2//photon/bin/Photon 10r READY — 57k 28k
0 37 //2//vesabios.ms 10o RECV 0 40k 28k
0 39 //2//drivers/Pg.vga4 12r REPLY 35 118k 118k
0 42 //2//bin/phfontall 10r RECV 0 159k 442k
0 50 //2//bin/Input.mdi8000 12o RECV 0 26k 28k
0 51 //2/minya/bin/gui 10o READY — 122k 114k
0 54 //2/*/bin/Input.mdi8000 10o RECV 0 26k 28k
0 58 //2/bin/Dev32.ser 20r RECV 0 16k 32k
0 64 //2/bin/tinit 10o WAIT -1 16k 28k
0 66 //2/minya/bin/hostif 10o REPLY 8 57k 32k
0 70 //2/bin/dumper 28o RECV 0 16k 20k
1 71 //2/bin/login 10o REPLY 8 24k 20k
2 72 //2/bin/sh 10o WAIT -1 94k 45k
2 84 //2/bin/sin 10o REPLY 1 45k 49k

-------------------- sin ver ---------------------------------
PROGRAM NAME VERSION DATE
sys/Proc32 Proc 4.25I Nov 25 1998
sys/Proc32 Slib16 4.23G Oct 04 1996
sys/Slib32 Slib32 4.24B Aug 12 1997
/bin/Fsys Fsys32 4.24S Jul 16 1998
/bin/Fsys Floppy 4.24B Aug 19 1997
/bin/Fsys.aha7scsi scsi 4.24M Mar 23 1998
//1/bin/Dev32 Dev32 4.23G Oct 04 1996
//1/bin/Dev32.ansi Dev32.ansi 4.23H Nov 21 1996
//1/bin/Dev32.ser Dev32.ser 4.23I Jun 27 1997
//1/bin/Dev32.par Dev32.par 4.23G Oct 04 1996
//1/bin/Dev32.pty Dev32.pty 4.23G Oct 04 1996
//1/bin/Mouse Mouse 4.24A Aug 22 1997
//1/bin/Iso9660fsys Iso9660fsys 4.23B Jun 10 1998
//1/bin/Pipe Pipe 4.23A Feb 26 1996
//1/bin/Net Net 4.25B Jul 27 1998
//1/bin/Net.ether1000 Net.ether100 4.24B Jul 24 1998
//1/usr/bin/lpsrvr lpsrvr 4.24A Jun 26 1997
//1//bin/phfontpfr Photon Font 1.13A Jul 07 1998
//1//usr/ucb/Socklet Socklet 4.25G Dec 08 1998
//1//photon/bin/Photon Photon 1.13D Sep 03 1998
//1//4.25/usr/ucb/Dns Dns 1.00C Jun 30 1998

------------------ sin info -----------------------------------
Node CPU Machine Speed Memory Ticksize Display Flags
2 486/487 AT 9708 4161k/7962k 10.0ms VGA Color -3-±---------8P

Heapp Heapf Heapl Heapn Hands Names Sessions Procs Timers Nodes Virtual
0 0 23256 0 64 100 64 500 125 4 6M/ 25M

Boot from Hard at — – --:-- Locators: 2

------------------ sin irq ------------------------------------
IRQ PID PROGRAM CS:IP DS
-1 8 /bin/Dev32 0005:005760 000D
-1 9 /bin/Dev32.ansi 0005:005DC0 000D
-1 58 //2/bin/Dev32.ser 0005:0024FC 000D
0 1 sys/Proc32 00F0:004CB3 00F8
1 9 /bin/Dev32.ansi 0005:00690C 000D
3 58 //2/bin/Dev32.ser 0005:00177C 000D
4 58 //2/bin/Dev32.ser 0005:0017A4 000D
7 28 //2/*/bin/supervisor 0005:00AE70 000D
13 1 sys/Proc32 00F0:004C77 00F8

Ken_Schumm1 · March 12, 2001, 4:36pm

That’s what I’m trying to track down now. I’ve got APM disabled
in the BIOS, but the Ampro docs state that disabling it in the
BIOS doesn’t disable APM. So, I’ve reenabled the BIOS and am
trying to get the free APM stuff working - no luck so far, but
I’m still beating on it.

I thought that APM low power mode was invoked by the idle process.
Since I wrote my own idle that spins fifo at priority 1, I thought
this would fix things but it seemed to have no effect.

What is the mechanism by which APM gets invoked?

Previously, Armin Steinhoff wrote in qdn.public.qnx4:

Hi Ken,

could it be that the handler of the SMI (System Management
Interrupt) does a lot at your machine?
This happens if you have enabled a lot of e.g. power
management actions on the board.

The SMI handler is located in the BIOS … I would try
to minimize all power management and similar activities.

Armin

Ken Schumm wrote:

We’re having some trouble getting consistent interrupt latency on
a QNX 4.25 embedded PC/104 product of ours. Usually the latency is
around 10-15 us as measured on a dso. Sometimes, though, maybe
.001% of the time, this latency stretches out to as much as 120 us.
We need a reliable 4 kHz collection rate, so these 120 us
disturbances often cause data to be lost.

Our product is based around an Ampro 4DXi board (486/133), with an
Ampro MiniModule/LCD II vga card and a custom data acquisition card
of our own design.

I think we have eliminated photon and the graphics subsystem
from consideration. We removed the video card and ran the system
without photon and our gui software with no improvement.

We thought perhaps that the cpu was being put into low power mode
by the idle process, so we wrote our own idle, that spins at
priority one. This made no difference.

Our data collection process is running at priority 29, and proc
at 28. We have rotated the data collection interrupt, using the
-i 7 option to proc, to make it the highest priority interrupt
in the box. We tried both -zn and -zN options to proc to no
avail.

We have also tried killing off most everything except the
main data collection process (supervisor) and this made no
difference.

Ideas are appreciated, sin info is below.

--------------------- sin ------------------------------------
SID PID PROGRAM PRI STATE BLK CODE DATA
– – Microkernel — ----- — 10448 0
0 1 sys/Proc32 28f READY — 118k 811k
0 2 sys/Slib32 10r RECV 0 53k 4096
0 4 /bin/Fsys 10r RECV 0 77k 409k
0 5 usr/local/tffs/Fsys.doc 10r RECV 0 36k 53k
0 8 /bin/Dev32 24f RECV 0 32k 90k
0 9 /bin/Dev32.ansi 20r RECV 0 40k 49k
0 10 idle 0r READY — 0 0
0 19 //2/bin/nameloc 20o RECV 0 6144 20k
0 20 //2/bin/nameloc 20o REPLY 0 6144 16k
0 24 //2/minya/bin/speaker 10o RECV 0 4096 12k
0 27 //2/minya/bin/dbmgr 10o RECV 0 20k 28k
0 28 //2//bin/supervisor 29f RECV 0 53k 24k
0 35 //2//photon/bin/Photon 10r READY — 57k 28k
0 37 //2//vesabios.ms 10o RECV 0 40k 28k
0 39 //2//drivers/Pg.vga4 12r REPLY 35 118k 118k
0 42 //2//bin/phfontall 10r RECV 0 159k 442k
0 50 //2//bin/Input.mdi8000 12o RECV 0 26k 28k
0 51 //2/minya/bin/gui 10o READY — 122k 114k
0 54 //2/*/bin/Input.mdi8000 10o RECV 0 26k 28k
0 58 //2/bin/Dev32.ser 20r RECV 0 16k 32k
0 64 //2/bin/tinit 10o WAIT -1 16k 28k
0 66 //2/minya/bin/hostif 10o REPLY 8 57k 32k
0 70 //2/bin/dumper 28o RECV 0 16k 20k
1 71 //2/bin/login 10o REPLY 8 24k 20k
2 72 //2/bin/sh 10o WAIT -1 94k 45k
2 84 //2/bin/sin 10o REPLY 1 45k 49k

-------------------- sin ver ---------------------------------
PROGRAM NAME VERSION DATE
sys/Proc32 Proc 4.25I Nov 25 1998
sys/Proc32 Slib16 4.23G Oct 04 1996
sys/Slib32 Slib32 4.24B Aug 12 1997
/bin/Fsys Fsys32 4.24S Jul 16 1998
/bin/Fsys Floppy 4.24B Aug 19 1997
/bin/Fsys.aha7scsi scsi 4.24M Mar 23 1998
//1/bin/Dev32 Dev32 4.23G Oct 04 1996
//1/bin/Dev32.ansi Dev32.ansi 4.23H Nov 21 1996
//1/bin/Dev32.ser Dev32.ser 4.23I Jun 27 1997
//1/bin/Dev32.par Dev32.par 4.23G Oct 04 1996
//1/bin/Dev32.pty Dev32.pty 4.23G Oct 04 1996
//1/bin/Mouse Mouse 4.24A Aug 22 1997
//1/bin/Iso9660fsys Iso9660fsys 4.23B Jun 10 1998
//1/bin/Pipe Pipe 4.23A Feb 26 1996
//1/bin/Net Net 4.25B Jul 27 1998
//1/bin/Net.ether1000 Net.ether100 4.24B Jul 24 1998
//1/usr/bin/lpsrvr lpsrvr 4.24A Jun 26 1997
//1//bin/phfontpfr Photon Font 1.13A Jul 07 1998
//1//usr/ucb/Socklet Socklet 4.25G Dec 08 1998
//1//photon/bin/Photon Photon 1.13D Sep 03 1998
//1//4.25/usr/ucb/Dns Dns 1.00C Jun 30 1998

------------------ sin info -----------------------------------
Node CPU Machine Speed Memory Ticksize Display Flags
2 486/487 AT 9708 4161k/7962k 10.0ms VGA Color -3-±---------8P

Heapp Heapf Heapl Heapn Hands Names Sessions Procs Timers Nodes Virtual
0 0 23256 0 64 100 64 500 125 4 6M/ 25M

Boot from Hard at — – --:-- Locators: 2

------------------ sin irq ------------------------------------
IRQ PID PROGRAM CS:IP DS
-1 8 /bin/Dev32 0005:005760 000D
-1 9 /bin/Dev32.ansi 0005:005DC0 000D
-1 58 //2/bin/Dev32.ser 0005:0024FC 000D
0 1 sys/Proc32 00F0:004CB3 00F8
1 9 /bin/Dev32.ansi 0005:00690C 000D
3 58 //2/bin/Dev32.ser 0005:00177C 000D
4 58 //2/bin/Dev32.ser 0005:0017A4 000D
7 28 //2/*/bin/supervisor 0005:00AE70 000D
13 1 sys/Proc32 00F0:004C77 00F8