QSPY  5.8.0
QSPY Screen Output

QSPY provides a simple consolidated, human-readable textual output to the screen. The readability of this output depends strongly on the availability of the symbolic information about the various objects in the Target code, called dictionaries. If the "dictionaries" are not available, QSPY can output only the hexadecimal values of various object addresses and event signals. However, if QSPY has acquired the "dictionaries" from the Target, or has read them from a file, it can apply the symbolic information to output the provided identifiers for objects, signals, and states.


Screen Output Example

For example, the following listing shows the QSPY text output when the "dictionaries" are available:

QSPY host application 5.5.0
Copyright (c) Quantum Leaps, state-machine.com
Time Stamp: 150914_131608
-v550
-T4
-O4
-F4
-S2
-E2
-Q1
-P2
-B2
-C2

********** TARGET: QP-Ver: 550, build tstamp:150831_144229
           Obj-Dic: 0000000000004018->QS_RX
           Obj-Dic: 0000000000003B18->l_SysTick_Handler
           Obj-Dic: 0000000000003B19->l_GPIOPortA_IRQHandler
           Usr-Dic: 00000046        ->PHILO_STAT
. . . . . .
           Fun-Dic: 0000000000000A79->Philo_initial
           Fun-Dic: 0000000000000D01->Philo_thinking
           Fun-Dic: 0000000000000C99->Philo_hungry
           Fun-Dic: 0000000000000C45->Philo_eating
           Sig-Dic: 0000000A,Obj=0000000020000D60->HUNGRY_SIG
           Sig-Dic: 0000000B,Obj=0000000020000D60->TIMEOUT_SIG
. . . . . .
0000500000 PHILO_STAT: 0 thinking
0000500000 PHILO_STAT: 1 thinking
0000500000 PHILO_STAT: 2 thinking
0000500000 PHILO_STAT: 3 thinking
0000500000 PHILO_STAT: 4 thinking
           INIT : Obj=l_table Source=NULL Target=Table_serving
           ENTRY: Obj=l_table State=Table_serving
0000500000 ==>Init: Obj=l_table New=Table_serving
0001000995 Disp==>: Obj=l_table Sig=SERVE_SIG Active=Table_serving
0001001751 Ignored: Obj=l_table Sig=SERVE_SIG Active=Table_serving
0025500773 Disp==>: Obj=l_philo[4] Sig=TIMEOUT_SIG Active=Philo_thinking
           ENTRY: Obj=l_philo[4] State=Philo_hungry
0025502307 ==>Tran: Obj=l_philo[4] Sig=TIMEOUT_SIG Source=Philo_thinking New=Philo_hungry
0025503277 Disp==>: Obj=l_table Sig=HUNGRY_SIG Active=Table_serving
0025503983 PHILO_STAT: 4 hungry
0025505703 PHILO_STAT: 4 eating
0025506279 Intern : Obj=l_table Sig=HUNGRY_SIG Source=Table_serving
0025507211 Disp==>: Obj=l_philo[4] Sig=EAT_SIG Active=Philo_hungry
           ENTRY: Obj=l_philo[4] State=Philo_eating
0025508581 ==>Tran: Obj=l_philo[4] Sig=EAT_SIG Source=Philo_hungry New=Philo_eating
0025509563 Disp==>: Obj=l_philo[3] Sig=EAT_SIG Active=Philo_thinking
0025510253 Intern : Obj=l_philo[3] Sig=EAT_SIG Source=Philo_thinking
. . . . . .

The QS trace log shown in the listing above contains quite detailed information, because most QS records are enabled (are not blocked in the "QS filters"). The following bullet items highlight the most interesting parts of the trace and illustrate how you can interpret the trace data:

  • The QS output starts with the QSPY application version number, the date and time of the run (Time Stamp), and all the options explicitly provided to the QSPY host application.
  • The first trace records in the log are typically dictionary trace records that provide a mapping between addresses of various objects in memory and their symbolic names.
  • After the dictionaries, you see the active object initialization. For example, the INIT record indicates that the top-most initial transition in the active object l_table has been taken. After this, the ENTRY record informs you that the state Table_serving has been entered, and finally the record ==>Init tells you that the top-most initial transition sequence has completed. This trace record has a high-resolution time-stamp (the first 8-digit number) generated by the Target. The time units used by this time-stamp depend on the specific hardware timer used in the Target, but typically it is sub-microsecond.
  • After this you see that at the time-stamp 0001000995 an event was dispatched (Disp==> record) to l_table, but it was subsequently Ignored, while l_table was in the state Table_serving.

Standard Trace Records

The following table summarizes the text output format used for all standard QS trace records (see ::•QSpyRecords).

QEP Trace Records

Rec.
Num.
Rec.
Enum.
QSPY
Abbrev.

Comment

1 QS_QEP_STATE_ENTRY Q_ENTRY

a state was entered

2 QS_QEP_STATE_EXIT Q_EXIT

a state was exited

3 QS_QEP_STATE_INIT Q_INIT

an intial transition was taken in a state

4 QS_QEP_INIT_TRAN ==>Init

the top-most initial transition was taken

5 QS_QEP_INTERN_TRAN Intern

an internal transition was taken

6 QS_QEP_TRAN ==>Tran

a regular transition was taken

7 QS_QEP_IGNORED Ignored

an event was ignored (silently discarded)

8 QS_QEP_DISPATCH Disp==>

an event was dispatched (begin of RTC step)

9 QS_QEP_UNHANDLED ==>UnHd

a guard prevented handling of an event

QF Trace Records

Rec.
Num.
Rec.
Enum.
QSPY
Abbrev.

Comment

10 QS_QF_ACTIVE_ADD ADD

an AO has been added to QF (started)

11 QS_QF_ACTIVE_REMOVE REM

an AO has been removed from QF (stopped)

12 QS_QF_ACTIVE_SUBSCRIBE SUB

an AO subscribed to an event

13 QS_QF_ACTIVE_UNSUBSCRIBE USUB

an AO unsubscribed to an event

14 QS_QF_ACTIVE_POST_FIFO AO.FIFO

an event was posted (FIFO) directly to AO

15 QS_QF_ACTIVE_POST_LIFO AO.LIFO

an event was posted (LIFO) directly to AO

16 QS_QF_ACTIVE_GET AO.GET

AO got an event and its queue is still not empty

17 QS_QF_ACTIVE_GET_LAST AO.GETL

AO got an event and its queue is empty

18 QS_QF_EQUEUE_INIT EQ.INIT

an event queue was initialized

19 QS_QF_EQUEUE_POST_FIFO EQ.FIFO

an event was posted (FIFO) to a raw queue

20 QS_QF_EQUEUE_POST_LIFO EQ.LIFO

an event was posted (LIFO) to a raw queue

21 QS_QF_EQUEUE_GET EQ.GET

get an event and queue still not empty

22 QS_QF_EQUEUE_GET_LAST EQ.GETL

get the last event from the queue

23 QS_QF_MPOOL_INIT MP.INIT

a memory pool was initialized

24 QS_QF_MPOOL_GET MP.GET

a memory block was removed from a memory pool

25 QS_QF_MPOOL_PUT MP.PUT

a memory block was returned to a memory pool

26 QS_QF_PUBLISH PUBLISH

an event was published

27 RESERVED

28 QS_QF_NEW NEW

new event creation

29 QS_QF_GC_ATTEMPT GC-ATT

garbage collection attempt

30 QS_QF_GC GC

garbage collection performed

31 QS_QF_TICK TICK

QF_tick() was called

32 QS_QF_TIMEEVT_ARM TE.ARM

a time event was armed

33 QS_QF_TIMEEVT_AUTO_DISARM TE.ADRM

a time event expired and was disarmed

34 QS_QF_TIMEEVT_DISARM_ATTEMPT TE.DATT

attempt to disarmed a disarmed tevent

35 QS_QF_TIMEEVT_DISARM TE.DARM

true disarming of an armed time event

36 QS_QF_TIMEEVT_REARM TE.RARM

rearming of a time event

37 QS_QF_TIMEEVT_POST TE.POST

a time event posted itself directly to an AO

38 QS_QF_TIMEEVT_CTR TE.CTR

a time event counter was requested

39 QS_QF_INT_DISABLE QF_intL

interrupts were disabled

40 QS_QF_INT_ENABLE QF_intU

interrupts were enabled

42 QS_QF_ISR_ENTRY QF_isrE

an ISR was entered

43 QS_QF_ISR_EXIT QF_isrX

an ISR was exited

QK/QV Trace Records

Rec.
Num.
Rec.
Enum.
QSPY
Abbrev.

Comment

50 #QS_QK_MUTEX_LOCK QK_muxL

the QK mutex was locked

51 #QS_QK_MUTEX_UNLOCK QK_muxU

the QK mutex was unlocked

52 #QS_QVK_SCHEDULE QVK_sche

the QV/QK scheduled a new task to execute

53 #QS_QVK_IDLE QVK_idle

QK/QV became idle

54 #QS_QK_RESUME QK_res

QK resumed previous task (not idle)

Additional QEP Trace Records

55 QS_QEP_TRAN_HIST QS.HIST

a transition to history was taken

56 QS_QEP_TRAN_EP QS.EP

a transition to entry point into a submachine

57 QS_QEP_TRAN_XP QS.XP

a transition to exit point into a submachine

Miscellaneous Trace Records
NOT MASKABLE WITH THE GLOBAL FILTER!

Rec.
Num.
Rec.
Enum.
QSPY
Abbrev.

Comment

60 QS_SIG_DICTIONARY Sig Dic

signal dictionary entry

61 QS_OBJ_DICTIONARY Obj Dic

object dictionary entry

62 QS_FUN_DICTIONARY Fun Dic

function dictionary entry

63 QS_USR_DICTIONARY Usr Dic

User record dictionary entry

64 QS_TARGET_INFO Info

reports the Target information

65 RESERVED

66 QS_RX_STATUS

reports QS data receive status

66 QS_TEST_STATUS

reports test status

66 QS_PEEK_DATA

reports the data from the PEEK query

67 QS_ASSERT_FAIL !ASSERT

Assertion fired

User (Application Specific) Records

70 QS_USER UserXXX the first record available for user QS records

Next: QSPY Dictionaries