MQTT - Timer Hogging

[ecasey]

Playing with the mqtt-paho example, I found that it uses up 3 of the 4 HiResTimers. It acquires three timers and keeps two active, using them occasionally. The third one is released and re-acquired throughout the publish-subscribe cycle.
The app I want to add mqtt to already uses two timers, so it crashes if I try to integrate this.
I tried hard-coding the init() function in class NBMQTTCountdown to use one specific timer (i.e. timer = HiResTimer::getHiResTimer(3);) and it seems to run on that one timer exactly as it did on three. I have had it running for a couple of days with the hard-coded timer number and it seems fine.
Is this going to blow up on me, or can it survive on one timer? I would also like to know how to restrict it to one timer without using a magic number.
I have listed the output before and after hard-coding the timer number at the end of this entry. Sorry they are so long - they are the connect-to-server, connect to broker, and two publish - subscribe cycles. The calling method is shown for each line

Ed

timer = HiResTimer::getHiResTimer();

[
Waiting 2sec to start 'A' to abort
Configured IP = 192.168.50.239
Configured Mask = 255.255.255.0
MAC Address= 00:03:f4:04:5c:fa
Application started
timer 0x20008e54 acquired
timer 0x20008e82 acquired
timer 0x20008eb0 acquired
timer 0x20008eb0 accessed-countdown_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e54 accessed-countdown_ms
timer 0x20008e54 accessed-countdown
timer 0x20008e82 accessed-countdown_ms
timer 0x20008e82 accessed-countdown
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e82 accessed-countdown_ms
timer 0x20008e82 accessed-countdown
timer 0x20008e54 accessed-expired
timer 0x20008e54 accessed-left_ms
timer 0x20008e82 accessed-expired
timer 0x20008e82 accessed-left_ms
timer 0x20008eb0 released
timer 0x20008eb0 acquired
timer 0x20008eb0 accessed-countdown_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e54 accessed-countdown_ms
timer 0x20008e54 accessed-countdown
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e82 accessed-countdown_ms
timer 0x20008e82 accessed-countdown
timer 0x20008e54 accessed-expired
timer 0x20008e54 accessed-left_ms
timer 0x20008e82 accessed-expired
timer 0x20008e82 accessed-left_ms
timer 0x20008eb0 released
timer 0x20008eb0 acquired
timer 0x20008eb0 accessed-countdown_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e54 accessed-countdown_ms
timer 0x20008e54 accessed-countdown
timer 0x20008eb0 released
timer 0x20008eb0 acquired
timer 0x20008eb0 accessed-countdown_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e82 accessed-countdown_ms
timer 0x20008e82 accessed-countdown
Message 1 arrived: qos 0, retained 0, dup 0, packetid 10618
Payload: nb-5CFA -> Uptime: 35
timer 0x20008e54 accessed-expired
timer 0x20008e54 accessed-left_ms
timer 0x20008e82 accessed-expired
timer 0x20008e82 accessed-left_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e54 accessed-expired
timer 0x20008e54 accessed-left_ms
timer 0x20008e82 accessed-expired
timer 0x20008e82 accessed-left_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 released
timer 0x20008eb0 acquired
timer 0x20008eb0 accessed-countdown_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e54 accessed-countdown_ms
timer 0x20008e54 accessed-countdown
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e82 accessed-countdown_ms
timer 0x20008e82 accessed-countdown
timer 0x20008e54 accessed-expired
timer 0x20008e54 accessed-left_ms
timer 0x20008e82 accessed-expired
timer 0x20008e82 accessed-left_ms
timer 0x20008eb0 released
timer 0x20008eb0 acquired
timer 0x20008eb0 accessed-countdown_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e54 accessed-countdown_ms
timer 0x20008e54 accessed-countdown
timer 0x20008eb0 released
timer 0x20008eb0 acquired
timer 0x20008eb0 accessed-countdown_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e82 accessed-countdown_ms
timer 0x20008e82 accessed-countdown
Message 2 arrived: qos 0, retained 0, dup 0, packetid 10618
Payload: nb-5CFA -> Uptime: 70
timer 0x20008e54 accessed-expired
timer 0x20008e54 accessed-left_ms
timer 0x20008e82 accessed-expired
timer 0x20008e82 accessed-left_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 accessed-left_ms
timer 0x20008e54 accessed-expired
timer 0x20008e54 accessed-left_ms
timer 0x20008e82 accessed-expired
timer 0x20008e82 accessed-left_ms
timer 0x20008eb0 accessed-expired
timer 0x20008eb0 accessed-left_ms
timer 0x20008eb0 released]


timer = HiResTimer::getHiResTimer(3);

[
Waiting 2sec to start 'A' to abort
Configured IP = 192.168.50.239
Configured Mask = 255.255.255.0
MAC Address= 00:03:f4:04:5c:fa
Application started
timer 0x20008ede acquired
timer 0x20008ede acquired
timer 0x20008ede acquired
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede released
timer 0x20008ede acquired
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede released
timer 0x20008ede acquired
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede released
timer 0x20008ede acquired
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
Message 1 arrived: qos 0, retained 0, dup 0, packetid 10618
Payload: nb-5CFA -> Uptime: 35
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede released
timer 0x20008ede acquired
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede released
timer 0x20008ede acquired
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
timer 0x20008ede released
timer 0x20008ede acquired
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-countdown_ms
timer 0x20008ede accessed-countdown
Message 2 arrived: qos 0, retained 0, dup 0, packetid 10618
Payload: nb-5CFA -> Uptime: 70
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede accessed-expired
timer 0x20008ede accessed-left_ms
timer 0x20008ede released
]

[pbreed]

What platform and NNDK version is this?

[ecasey]

MOD5282 and MOD5270B, same on both, with NNDK 2.9.5

[pbreed]

Yes this is broken....
The NBMQTTCountdown.h should be rewritten to use either TimeTick or GetPreciseTime()

Both the MOD5282 and MOD5270 support :
+DWORD GetPreciseTime( void )
This gives you a high precision time counter based on the PIT counter...remainder and time ticks.
The downside is that the scale is different... on the 5282 each count from GetPreciseTime is 1.929 uSec.
On the 5270 its about 0.868 usec per count.

extern const unsigned long CPU_CLOCK;
extern unsigned short BspTickMaxCount;

The variable (BspTickMaxCount * TICKS_PER_SECOND)/1000 should give you the number of GetPeeciseTime counts per msec.
This will however roll over quite quickly, so you need to handle that too....




I can't get to that until next week.
On first examination it looks like the values passed in are all whole seconds so TimeTick should probably work, but this is not my code and I have not dug deep enough to be 100% sure this is true.
IE Is the _ms version of that is used in any meaningful way... other than called with whole seconds *1000

[pbreed]

I believe I have a fix. Submit a support request and I'll send it.
It will be up on github sometime in a day or two. (need to QA it)

Paul

[ecasey]

The timer resolution is seconds as set in NBMQTTCountdown.h at lines 36 and 52 using

Code: Select all

((TimeTick/TICKS_PER_SECOND) * 1000) 

to set startTime and time respectively. Seconds should be fine mostly since all the settable parameters are in seconds, except

Code: Select all

 int Client::yield(unsigned long timeout_ms = 1000L)

at line 228 in MQTTClient.h which accepts ms as the parameter. The yield() time-out must be lower than the broker's time-out, which I don't think is known in advance. From what I can see, none of the brokers seem to be below 1 second, usually 60 to 90 seconds, so the yield() time-out can probably be in seconds as well. It should be clear that it is in seconds. I will send a support request and have a look a it.

Thanks
Ed

[pbreed]

Just for completness.
This issue has been resolved. And new code will be posted to github in the next 48 hours.