Real Time Analysis

As per the suggestion below, I have tried to use the QNX Trace commands.

  1. My make files contain the “-T1” that is req’d.
  2. Added “Trace0(_TRACE_TEMPORARY, _TRACE_TRANSIENT);” at the point that my
    s/w detects that we are late sending a WDT message (see my original problem
    description for details).
  3. Added “Trace1(_TRACE_TEMPORARY, _TRACE_TESTING, 1);” at the point where I
    send a WDT message.
  4. Typed the following at the Ksh prior to starting my app:
    tracelogger -f/csvs/sys/trace%m%d -t10 -p80 &
  5. I’ve got a trace file but it does not tell me much, used traceinfo to
    convert file to text format.

Questions:

  1. What am I doing wrong when using tracer ?
    or
  2. Is this output typical and does it flag my problem?

Also, before when I said “I’ve been able to generate a monitor file
containing
the events surrounding the condition”. I meant that I was able to generate a
file containing the events around the TIME that things went a muck. I am
still trying to pin down “who is the culprit”, OS or my App.

On another note: I also expanded my window for storing deja-view data to
include the file i/o and my problem nolonger occurred. Weird!!!


begin 666 trace1.txt
M1&5C(#,Q(#$Y.C P.C T(#4@,# P,#4Q,#D@4V-S:2!S96YS92 H=6YI=#TP
M(’-C<VD],B!E<G(]-S!H(’-E;G-E/35H(&%S8STR-&@@87-C<3TP:“D-“D1E
M8R S,2 Q.3HP,#HP-” U(# P,# U,3 Y(%-C<VD@<V5N<V4@‘5N:70],"!S
M8W-I/3(@97)R/3<P:"!S96YS93TU:"!A<V,],C1H(&%S8W$],&@I#0I$96,@
M,S$@,3DZ,# Z,#0@-2 P,# P-3$P.2!38W-I(’-E;G-E(“AU;FET/3 @<V-S
M:3TR(&5R<CTW,&@@<V5N<V4]-6@@87-C/3(T:”!A<V-Q/3!H
0T1&5C(#,Q
M(#$Y.C P.C T(#4@,# P,#4Q,#D@4V-S:2!S96YS92 H=6YI=#TP(’-C<VD]
M,B!E<G(]-S!H(’-E;G-E/35H(&%S8STR-&@@87-C<3TP:"D-“D1E8R S,2 Q
M.3HP,#HP-” U(# P,# U,3 Y(%-C<VD@<V5N<V4@
'5N:70],”!S8W-I/3(@
M97)R/3<P:"!S96YS93TU:"!A<V,],C1H(&%S8W$],&@I#0I$96,@,#4@,#DZ
M,S@Z-3,@,R P,# P,S P-"!“860@8FQO8VL@,# P,# P,#$@;VX@+V1E=B]F
M9# @9’5R:6YG(’)E860-“D1E8R P-2 P.3HS.#HU-” S(# P,# V,# W(#0@
M8VQU<W1E<G,@86QL;V-A=&5D(&%T(#9%.4(P#0I$96,@,#4@,#DZ,S@Z-30@
M,R P,# P-C P82 Q,”!M8G5F<R!A;&QO8V%T960@870@-S<V.# -“D1E8R P
M-2 P.3HS.#HU-” S(# P,# V,#!A(#$P(&UB=69S(&%L;&]C871E9"!A=" W
M.#(X, T1&5C(# U(# Y.C,X.C4U(#,@,# P,#8P,&$@,3 @;6)U9G,@86QL
M;V-A=&5D(&%T(#<X1# P#0I$96,@,#4@,#DZ,S@Z-34@,R P,# P,S P-B!#
M86-H92!F;W(@+V1E=B]F9# @:6YV86QI9&%T960@8GD@=&EM96]U= T
1&5C
M(# U(# Y.C,Y.C Y(#(@,# P,#0P,S<@,# P,# P,#$@,# P,#4P,# @,# P
M,#@Q,#0@,# P,#4X,#@@( T*1&5C(# U(# Y.C0Q.C4Q(#,@,# P,# P,#$@
M3F]D92 V(#H@0F]O=&5D(&]N(%1U92!$96,@(#4@,#DZ,S@Z-#,@,C P," Z
M(“I(87)D($)O;W0@#0I$96,@,#4@,#DZ-#4Z,S$@,B!F9F9F9C P,” P,# P
:,# P," P,# P,# P," P,# P,# P," @#0H
end

“Bill Shadid” <bshadid@neptec.com> wrote in message
news:90joi4$snc$1@inn.qnx.com

As per the suggestion below, I have tried to use the QNX Trace commands.

  1. My make files contain the “-T1” that is req’d.
  2. Added “Trace0(_TRACE_TEMPORARY, _TRACE_TRANSIENT);” at the point that
    my
    s/w detects that we are late sending a WDT message (see my original
    problem
    description for details).
  3. Added “Trace1(_TRACE_TEMPORARY, _TRACE_TESTING, 1);” at the point where
    I
    send a WDT message.
  4. Typed the following at the Ksh prior to starting my app:
    tracelogger -f/csvs/sys/trace%m%d -t10 -p80 &
  5. I’ve got a trace file but it does not tell me much, used traceinfo to
    convert file to text format.

The _TRACE_TESTING is not logged by default you need
to use tracectrl -s7 to allow the log to be included in the buffer

Questions:

  1. What am I doing wrong when using tracer ?
    or
  2. Is this output typical and does it flag my problem?

Also, before when I said “I’ve been able to generate a monitor file
containing
the events surrounding the condition”. I meant that I was able to generate
a
file containing the events around the TIME that things went a muck. I am
still trying to pin down “who is the culprit”, OS or my App.

On another note: I also expanded my window for storing deja-view data to
include the file i/o and my problem nolonger occurred. Weird!!!

Bill,

In order to get useful information from traces, you need to instrument
processes besides the one that is experiencing the pre-emption (since
the goal is to find out which process is doing the long pre-emption -
and where within that process the long pre-emptionis occuring).

If all processes are peppered with trace calls, then you should
be able to see which one of the other processes is is active when
you experience the pre-emption condition (you should be able to
put a timer around the call where the long pre-emption occurs, and
only do a trace when this happens - therefore you simply need to
do a search for that trace, and look at the context to see who
pre-empted you).

I understand (and understood) your meaning of “events surrounding
the condition”, and if you have a monitor of the events surrounding
the condition, then you should already know what process was
active when the condition occured (it should be the process
scheduled immediately before the process that exhibits “the event”

  • i.e. the return from the call after a long time). The tracing will
    simply narrow down exactly what the offending process is doing at
    the time that you process is pre-empted. The fact that you know
    the active process means you don’t need to “pepper” all of your
    processes with trace calls, and this is what I meant when I said that
    this should be able to be done quickly. It is my opinion, that all real-
    time systems should contain liberal quantities of trace calls throughout
    all the applications that make up the system. Only when it would
    be a compromise to a deadline, should trace calls be considered
    optional (it doesn’t really matter that a real-time system takes a
    few less microseconds to execute if it doesn’t work because you
    can’t debug it). In the cases where trace calls can not be used,
    DejaView shines (since at least you can see what the scheduler
    is doing).

btw: There is no way that anything in the O/S is pre-empting your
process for 2.5 seconds, barring bad hardware, and assuming
the obvious things aren’t occuring (i.e. your process having a
lower priority than Proc, and process loads happening from
a slow network or very slow disk).

Rennie

“Bill Shadid” <bshadid@neptec.com> wrote in message
news:90joi4$snc$1@inn.qnx.com

As per the suggestion below, I have tried to use the QNX Trace commands.

  1. My make files contain the “-T1” that is req’d.
  2. Added “Trace0(_TRACE_TEMPORARY, _TRACE_TRANSIENT);” at the point that
    my
    s/w detects that we are late sending a WDT message (see my original
    problem
    description for details).
  3. Added “Trace1(_TRACE_TEMPORARY, _TRACE_TESTING, 1);” at the point where
    I
    send a WDT message.
  4. Typed the following at the Ksh prior to starting my app:
    tracelogger -f/csvs/sys/trace%m%d -t10 -p80 &
  5. I’ve got a trace file but it does not tell me much, used traceinfo to
    convert file to text format.

Questions:

  1. What am I doing wrong when using tracer ?
    or
  2. Is this output typical and does it flag my problem?

Also, before when I said “I’ve been able to generate a monitor file
containing
the events surrounding the condition”. I meant that I was able to generate
a
file containing the events around the TIME that things went a muck. I am
still trying to pin down “who is the culprit”, OS or my App.

On another note: I also expanded my window for storing deja-view data to
include the file i/o and my problem nolonger occurred. Weird!!!