QSpy Output Documentation?

[Timothy]

I've been looking through the QSPY output of my project and I'm not clear on the exact meaning of all the outputs values. I've looked around but have not yet found documentation that describes each type of standard output from QSPY. Could someone point me in the direction of what I'm looking for?

[Quantum Leaps]

QSPY is part of the QTools Collection. Consequently, the documentation of QSPY is here:

https://state-machine.com/qtools/qspy.html

There is of course much more to it than just the QSPY host application. The whole QP/Spy software tracing and software testing system is documented there as well:

https://state-machine.com/qtools/qpspy.html

I hope this helps.

--MMS

[Timothy]

I'll check it out. Thanks!

[Timothy]

Is there a page that describes the specifics of what QSpy outputs to the screen?

For instance, for a QS_QF_EQUEUE_GET record there can be the Object, Signal, Pool, Ref, & Que attributes that are outputted. The meaning of Object & Signal attributes are clear. However is there a description of how Pool, Ref, & Que are to be interpreted?

[Quantum Leaps]

https://state-machine.com/qtools/qspy_text.html

On a side note, it seems that the structure of the documentation is not "intuitive" or "self-explanatory" to you. Please suggest improvements, so that you can find the relevant information quickly, without the need to post questions to the forum.

--MMS

[Timothy]

I did come across that page earlier, so I was able to understand the structure of the documentation. However for the QSpy text output of:
AO-Get Obj=AO_Test,Evt<Sig=Test_SIG,Pool=2,Ref=1>,Que<Used=19>
where in that linked page does it document what Que<Used=19> means?

All I see for a description of this is:

Record Enum: QS_QF_ACTIVE_GET
Start of Record: <timestamp> AO-Get   
Description: AO got an event and its queue is still not empty

[Quantum Leaps]

Que<Used=19> means that the queue has 19 used entries in it (19 events).

This is supposed to be the "self-explanatory" part...

--MMS

[Timothy]

And that's what I had thought it meant. However upon reading through some QSpy output and the QF Source code, I don't understand how that can be the case.

Here's a snippet of a recent QSpy output:

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=12>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=68

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=13>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=69

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=14>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=70

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=15>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=71

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=16>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=72

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=17>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=73

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=18>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=74

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=19>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=75

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=20>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=76

AO-Get   Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>,Que<Used=21>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=77

AO-GetL  Obj=AO_Test,Evt<Sig=TEST_SIG,Pool=2,Ref=1>
QF-gc    Evt<Sig=TEST_SIG,Pool=2,Ref=1>
MP-Put   Obj=l_medPoolSto,Free=78

The AO_Test has a 21 slot capacity Queue, and the Medium Pool has 80 slots. Looking at this QSpy output it appears that as the MP-Put's "Free" increases, so does the AO_Get's "Que<Used".
And when the Queue is about to be empty (GetL), the Medium Pool is near its maximum "Free" and the GetL's "Used" is not displayed.

Additionally, inside the qf_actq.c it appears that the QF_ACTIVE_GET[_LAST] QSpy record is generated conditionally with two different sets of code lines. When the queue is empty, then it signals a QF_ACTIVE_GET_LAST and doesn't append the "Que<Used>" to the end of the record.

However when the queue is not empty, then it signals QF_ACTIVE_GET and the "Que<Used" is passed the unsigned value of "nFree".

I interpret "used entries" to mean entries that contain data waiting to be delivered, and that can't be reused yet. However my observations don't align with that interpretation.

Can you clarify why these don't appear to agree?

[Quantum Leaps]

Good catch. It seems that the QSPY output AO-Get ...Que<Used=..> should really be AO-Get ...Que<Free=..>. This will be fixed in the next QSPY release (next QTools).

Thank you for pointing this out. Could you perhaps file a bug report for this?

--MMS

[Timothy]

Thanks!

I've filed the bug. Turns out that QS_QF_ACTIVE_GET & QS_QF_EQUEUE_GET use the same output string, so both are affected.

[Quantum Leaps]

The bug#175 "QS_QF_ACTIVE_GET & QS_QF_EQUEUE_GET Record Mislabeled in QSPY Output" was fixed in QSPY/QTools 5.9.3.
--MMS