ROSpec stopping

All questions related to the usage of Rifidi Emulator

Moderators: Matt, kyle, Moderators

Post Reply
grahamc
Posts: 9
Joined: Mon May 19, 2008 1:48 pm
Organization: AAI

ROSpec stopping

Post by grahamc » Tue May 20, 2008 3:48 am

I'm trying to get Rifidi set up to send continuous notification of tags in view, but am finding that the data stops after a few seconds. As far as I can see there's nothing defined in the RO or AI specs that will shut it down, and I can't restart it by issuing a "start ROSpec" or by disabling and re-enabling it. Here's a sample conversation- starting from a position where any existing specs have been deleted. I've removed the few seconds of repeated tag detection messages. At the end is my client realising the server's been quiet for a few seconds and giving it a poke. This is Rifidi1.5 using a single LLRP Reader.



BYTES:
04 03 00 00 00 65 00 00 00 06 00 00 F4 00 43 00 F5 00 07 00 00 00 00 F5 00 07 00 01 80 00 F5 00 07 00 02 80 00 F5 00 07 00 03 00 00 F5 00 07 00 04 00 00 F5 00 07 00 05 00 00 F5 00 07 00 06 80 00 F5 00 07 00 07 00 00 F5 00 07 00 08 00 00 ED 00 12 02 00 00 00 EE 00 0B 00 00 01 5C 00 05 C0 00 EF 00 05 00
XML:
<Message type="SetReaderConfig">
<ResetToFactoryDefaults value="false"/>
<ReaderEventNotificationSpec>
<EventNotificationState>
<EventType value="0"/>
<NotificationState value="false"/>
</EventNotificationState>
<EventNotificationState>
<EventType value="1"/>
<NotificationState value="true"/>
</EventNotificationState>
<EventNotificationState>
<EventType value="2"/>
<NotificationState value="true"/>
</EventNotificationState>
<EventNotificationState>
<EventType value="3"/>
<NotificationState value="false"/>
</EventNotificationState>
<EventNotificationState>
<EventType value="4"/>
<NotificationState value="false"/>
</EventNotificationState>
<EventNotificationState>
<EventType value="5"/>
<NotificationState value="false"/>
</EventNotificationState>
<EventNotificationState>
<EventType value="6"/>
<NotificationState value="true"/>
</EventNotificationState>
<EventNotificationState>
<EventType value="7"/>
<NotificationState value="false"/>
</EventNotificationState>
<EventNotificationState>
<EventType value="8"/>
<NotificationState value="false"/>
</EventNotificationState>
</ReaderEventNotificationSpec>
<ROReportSpec>
<ROReportTrigger value="2"/>
<N value="0"/>
<TagReportContentSelector>
<EnableROSpecID value="false"/>
<EnableSpecIndex value="false"/>
<EnableInventoryParameterSpecID value="false"/>
<EnableAntennaID value="false"/>
<EnableChannelIndex value="false"/>
<EnablePeakRSSI value="false"/>
<EnableFirstSeenTimestamp value="false"/>
<EnableLastSeenTimestamp value="false"/>
<EnableTagSeenCount value="false"/>
<EnableAccessSpecID value="false"/>
<C1G2EPCMemorySelector>
<EnableCRC value="true"/>
<EnablePCBits value="true"/>
</C1G2EPCMemorySelector>
</TagReportContentSelector>
</ROReportSpec>
<AccessReportSpec>
<AccessReportTrigger value="0"/>
</AccessReportSpec>
</Message>


BYTES:
04 0D 00 00 00 18 00 00 00 06 01 1F 00 0E 00 00 00 06 53 75 63 65 73 73
XML:
<Message type="SetReaderConfigResponse">
<LLRPStatus>
<ErrorCode value="0"/>
<ErrorDescription value="Sucess"/>
</LLRPStatus>
</Message>


BYTES:
04 14 00 00 00 72 00 00 00 06 00 B1 00 68 00 00 00 01 00 00 00 B2 00 1E 00 B3 00 11 02 00 B4 00 0C 00 00 00 00 00 00 00 0A 00 B6 00 09 00 00 00 00 00 00 B7 00 2E 00 01 00 01 00 B8 00 09 01 00 00 00 BE 00 BA 00 1D 00 01 01 00 DE 00 16 00 01 00 DF 00 06 00 01 00 E0 00 0A 00 01 00 01 00 01 00 ED 00 12 02 00 00 00 EE 00 0B 00 00 01 5C 00 05 C0
XML:
<Message type="AddROSpec">
<ROSpec>
<ROSpecID value="1"/>
<Priority value="0"/>
<CurrentState value="0"/>
<ROBoundarySpec>
<ROSpecStartTrigger>
<ROSpecStartTriggerType value="2"/>
<PeriodicTriggerValue>
<Offset value="0"/>
<Period value="10"/>
</PeriodicTriggerValue>
</ROSpecStartTrigger>
<ROSpecStopTrigger>
<ROSpecStopTriggerType value="0"/>
<DurationTriggerValue value="0"/>
</ROSpecStopTrigger>
</ROBoundarySpec>
<AISpec>
<AntennaElement value="1"/>
<AISpecStopTrigger>
<AISpecStopTriggerType value="1"/>
<DurationTrigger value="190"/>
</AISpecStopTrigger>
<InventoryParameterSpec>
<InventoryParameterSpecID value="1"/>
<ProtocolID value="1"/>
<AntennaConfiguration>
<AntennaId value="1"/>
<RFReceiver>
<ReceiverSensitivity value="1"/>
</RFReceiver>
<RFTransmitter>
<HopTableId value="1"/>
<ChannelIndex value="1"/>
<TransmitPower value="1"/>
</RFTransmitter>
</AntennaConfiguration>
</InventoryParameterSpec>
</AISpec>
<ROReportSpec>
<ROReportTrigger value="2"/>
<N value="0"/>
<TagReportContentSelector>
<EnableROSpecID value="false"/>
<EnableSpecIndex value="false"/>
<EnableInventoryParameterSpecID value="false"/>
<EnableAntennaID value="false"/>
<EnableChannelIndex value="false"/>
<EnablePeakRSSI value="false"/>
<EnableFirstSeenTimestamp value="false"/>
<EnableLastSeenTimestamp value="false"/>
<EnableTagSeenCount value="false"/>
<EnableAccessSpecID value="false"/>
<C1G2EPCMemorySelector>
<EnableCRC value="true"/>
<EnablePCBits value="true"/>
</C1G2EPCMemorySelector>
</TagReportContentSelector>
</ROReportSpec>
</ROSpec>
</Message>


BYTES:
04 1E 00 00 00 2B 00 00 00 06 01 1F 00 21 00 00 00 19 52 4F 53 50 65 63 20 73 75 63 63 65 73 73 66 75 6C 6C 79 20 61 64 64 65 64
XML:
<Message type="AddROSpecResponse">
<LLRPStatus>
<ErrorCode value="0"/>
<ErrorDescription value="ROSPec successfully added"/>
</LLRPStatus>
</Message>


BYTES:
04 18 00 00 00 0E 00 00 00 06 00 00 00 01
XML:
<Message type="EnableROSpec">
<ROSpecID value="1"/>
</Message>


BYTES:
04 22 00 00 00 31 00 00 00 06 01 1F 00 27 00 00 00 1F 52 4F 53 50 65 63 20 77 61 73 20 73 75 63 63 65 73 73 66 75 6C 6C 79 20 65 6E 61 62 6C 65 64
XML:
<Message type="EnableROSpecResponse">
<LLRPStatus>
<ErrorCode value="0"/>
<ErrorDescription value="ROSPec was successfully enabled"/>
</LLRPStatus>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 93 5C 2B 08 00 F9 00 0D 00 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269149109000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 93 64 FC D8 00 F9 00 0D 00 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269149687000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 93 6A 3C 98 00 F9 00 0D 00 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269150031000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 93 6F B6 F0 00 F9 00 0D 00 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269150390000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 25 00 00 00 00 00 F6 00 1B 00 80 00 0C 00 04 4D A4 93 75 6F C8 00 FE 00 0B 00 00 00 00 01 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269150765000"/>
</UTCTimestamp>
<AISpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<SpecIndex value="0"/>
</AISpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3D 00 00 00 38 00 00 00 00 00 F0 00 17 8D 35 A1 FF 34 4E 42 5E EB 8C AD 93 CD 8B 00 00 8C 00 00 00 F0 00 17 8D 35 CE 9F B2 84 05 02 A6 E8 E6 88 03 8B 00 00 8C 00 00
XML:
<Message type="ROAccessReport">
<TagReportData>
<EPC96>
<EPC value="35 A1 FF 34 4E 42 5E EB 8C AD 93 CD "/>
</EPC96>
<C1G2CRC>
<CRC value="0"/>
</C1G2CRC>
<C1G2PC>
<PC value="0"/>
</C1G2PC>
</TagReportData>
<TagReportData>
<EPC96>
<EPC value="35 CE 9F B2 84 05 02 A6 E8 E6 88 03 "/>
</EPC96>
<C1G2CRC>
<CRC value="0"/>
</C1G2CRC>
<C1G2PC>
<PC value="0"/>
</C1G2PC>
</TagReportData>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 93 75 6F C8 00 F9 00 0D 01 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269150765000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="1"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 93 75 AE 48 00 F9 00 0D 00 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269150781000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 25 00 00 00 00 00 F6 00 1B 00 80 00 0C 00 04 4D A4 93 7B 67 20 00 FE 00 0B 00 00 00 00 01 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269151156000"/>
</UTCTimestamp>
<AISpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<SpecIndex value="0"/>
</AISpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3D 00 00 00 38 00 00 00 00 00 F0 00 17 8D 35 A1 FF 34 4E 42 5E EB 8C AD 93 CD 8B 00 00 8C 00 00 00 F0 00 17 8D 35 CE 9F B2 84 05 02 A6 E8 E6 88 03 8B 00 00 8C 00 00
XML:
<Message type="ROAccessReport">
<TagReportData>
<EPC96>
<EPC value="35 A1 FF 34 4E 42 5E EB 8C AD 93 CD "/>
</EPC96>
<C1G2CRC>
<CRC value="0"/>
</C1G2CRC>
<C1G2PC>
<PC value="0"/>
</C1G2PC>
</TagReportData>
<TagReportData>
<EPC96>
<EPC value="35 CE 9F B2 84 05 02 A6 E8 E6 88 03 "/>
</EPC96>
<C1G2CRC>
<CRC value="0"/>
</C1G2CRC>
<C1G2PC>
<PC value="0"/>
</C1G2PC>
</TagReportData>
</Message>
.
.
.
.


BYTES:
04 3D 00 00 00 38 00 00 00 00 00 F0 00 17 8D 35 A1 FF 34 4E 42 5E EB 8C AD 93 CD 8B 00 00 8C 00 00 00 F0 00 17 8D 35 CE 9F B2 84 05 02 A6 E8 E6 88 03 8B 00 00 8C 00 00
XML:
<Message type="ROAccessReport">
<TagReportData>
<EPC96>
<EPC value="35 A1 FF 34 4E 42 5E EB 8C AD 93 CD "/>
</EPC96>
<C1G2CRC>
<CRC value="0"/>
</C1G2CRC>
<C1G2PC>
<PC value="0"/>
</C1G2PC>
</TagReportData>
<TagReportData>
<EPC96>
<EPC value="35 CE 9F B2 84 05 02 A6 E8 E6 88 03 "/>
</EPC96>
<C1G2CRC>
<CRC value="0"/>
</C1G2CRC>
<C1G2PC>
<PC value="0"/>
</C1G2PC>
</TagReportData>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 94 5C F1 68 00 F9 00 0D 01 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269165937000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="1"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 94 5F 91 48 00 F9 00 0D 00 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269166109000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 25 00 00 00 00 00 F6 00 1B 00 80 00 0C 00 04 4D A4 94 60 48 E0 00 FE 00 0B 00 00 00 00 01 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269166156000"/>
</UTCTimestamp>
<AISpecEvent>
<EventType value="0"/>
<ROSpecID value="1"/>
<SpecIndex value="0"/>
</AISpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
04 3F 00 00 00 27 00 00 00 00 00 F6 00 1D 00 80 00 0C 00 04 4D A4 94 60 48 E0 00 F9 00 0D 01 00 00 00 01 00 00 00 00
XML:
<Message type="ReaderEventNotification">
<ReaderEventNotificationData>
<UTCTimestamp>
<Microseconds value="1211269166156000"/>
</UTCTimestamp>
<ROSpecEvent>
<EventType value="1"/>
<ROSpecID value="1"/>
<PreemptingROSpecID value="0"/>
</ROSpecEvent>
</ReaderEventNotificationData>
</Message>


BYTES:
00 3E 00 00 00 0A 00 00 00 06
XML:
<Message type="KeepAlive">
</Message>


BYTES:
04 64 00 00 00 12 00 00 00 06 01 1F 00 08 00 6E 00 00
XML:
<Message type="ErrorMessage">
<LLRPStatus>
<ErrorCode value="110"/>
<ErrorDescription value=""/>
</LLRPStatus>
</Message>

grahamc
Posts: 9
Joined: Mon May 19, 2008 1:48 pm
Organization: AAI

Re: ROSpec stopping

Post by grahamc » Tue May 20, 2008 1:51 pm

Hmm. Things seem much better if I actually specify a stop trigger for the ROSpec, such that the spec stops before the next periodic start condition comes along.

Surely if a periodic start condition arrives while an ROSpec is running it shouldn't cause a problem? An ROSpec can't pre-empt itself surely, since I'd have expected a pre-empting ROSpec to require a higher priority.

If an ROSpec doesn't stop on completion of all AISpecs, when *does* it stop if there is no stop trigger? Will it complete and then just hang until either explicitly stopped or pre-empted? That doesn't seem right since it'll then be stuck there doing nothing when there may be other ROSpecs of the same or lower priority waiting to run.

Googling around, I notice some debate as to the interpretation of the "immediate" start trigger, with someone pointing to a table in the spec and suggesting immediate start should cause an ROSpec to restart on completion if it's the only ROSpec in there, since the state diagram is a closed loop until an ROSpec is disabled or deleted. This doesn't seem to happen in Rifidi; do we already have different dialects forming that different readers will speak, and that we're going to have to work around?

grahamc
Posts: 9
Joined: Mon May 19, 2008 1:48 pm
Organization: AAI

Re: ROSpec stopping

Post by grahamc » Wed May 21, 2008 8:20 am

Hmm, better but still not right. Move a few windows around and suddenly Rifidi stops sending tag notifications back.

grahamc
Posts: 9
Joined: Mon May 19, 2008 1:48 pm
Organization: AAI

Re: ROSpec stopping

Post by grahamc » Fri May 23, 2008 6:21 am

Continuing for completeness, if I try setting the start trigger to "null" and have my code send an ROSpec start shortly after the spec stops I get the same effect- works for a while and then Rifidi stops responding. I can still list the ROSpecs and see that the spec is hung in the "Active" state. If I try disabling it in order to delete, I never get a response to the disable spec command and subsequent listings show the spec's still active.

kyle
Posts: 220
Joined: Tue Apr 22, 2008 10:12 pm
Name: Kyle
Organization: Pramari
Location: Hartford, CT
Contact:

Re: ROSpec stopping

Post by kyle » Fri May 23, 2008 11:20 am

Craig,
I'll look into it more deeply, but I'm wondering if the short times (190 ms and 10ms) are messing something up. I haven't done extensive testing with short times.

Also, about the Immediate start Trigger - I have re-read the explanation Gordon gave for why the Immediate start trigger should restart a rospec once it has executed, and it makes more sense to me than it did 6 months ago. I'll change that next week, and it will be in our repos. In the mean time, I'll do some investigation as to why the ROSpec is halting in the Active state, because that shouldn't ever happen.

-Kyle

grahamc
Posts: 9
Joined: Mon May 19, 2008 1:48 pm
Organization: AAI

Re: ROSpec stopping

Post by grahamc » Sat May 24, 2008 1:41 pm

Thanks for the response.

It does look like a speed issue. I've changed the ROSpec period to 2s and the AISpec duration to 1s and it survives long enough for me to drink a mug of coffee- much better than before. For real life I want to go as quickly as possible- someone could walk through a doorway in less than 2s and miss being scanned, if that's what we end up doing with this at some point. But for getting the app code done against a simulator, speed isn't so important.

Rifidi's taking up all the CPU when running at this rate, and had to lower the process priority to get everything else to run smoothly. Once I closed the console window (hiding it wasn't sufficient) the load dropped to pretty much nothing.

Hmm. Tomorrow I'll see if I can increase the rate again, keeping the console window closed, and see if it helps.

grahamc
Posts: 9
Joined: Mon May 19, 2008 1:48 pm
Organization: AAI

Re: ROSpec stopping

Post by grahamc » Sun May 25, 2008 9:54 am

'Tis now tomorrow, but no- running tag detection quickly with the console window closed causes the ROSpec to freeze within a minute or so.

Though it does run rather nicely for that minute.

So ROSpec period 2s and AI spec duration 1s is fine for >10 minutes, 200ms and 100ms hang in around a minute.

It occurred to me to try ruling out problems in receiving the messages in my app, so I tried connecting using a simple telnet client after using my app to configure the reader and then quitting. With a 2s period I get the binary data appearing on the screen every two seconds, whereas after the hang I see the initial connection response and then nothing.

kyle
Posts: 220
Joined: Tue Apr 22, 2008 10:12 pm
Name: Kyle
Organization: Pramari
Location: Hartford, CT
Contact:

Re: ROSpec stopping

Post by kyle » Sun May 25, 2008 5:06 pm

Craig,
I have been able to duplicate the bug, and I'll do some investigation into it. I found a race condition on Friday that causes the Periodic Trigger to keep firing even when the ROSpec is disabled, so the problem might be related to that. In any case, this will probably be a tough bug to fix. I entered the bugs in our bug tracker (1972045 and 1972048) on sourceforge, and will be trying my best to fix them this week.

That's also interesting about rifidi taking up so much CPU time when executing with the console window open. We've noticed this with another one of our applications (Tag Streamer), and know that the problem has to do with the logging. I haven't considered whether or not logging could be affecting ROSpec execution. I also want to investigate how changing the logging levels in our log4j configuration affects speed.

Thanks for your input in this (these kind of bugs are hard to find without users). As I said, I will be working on these issues and will post to the forum and change the tracker when the bug is fixed in our svn. I'm not sure if you build from source or not (we have a nice, public svn now. see: http://wiki.rifidi.org/index.php/Rifidi:Source_Code), but if you need the fixes sooner rather than later, feel free to do try it out.

Post Reply

Who is online

Users browsing this forum: No registered users and 4 guests