Issue with Logger Module?

jgummeson

Are there any known issues with the Logger module? I'm using the Android API with Android 5.1 and an OG Moto X.

My basic flow is as flows:

0. Clear previous timer tasks, 

1. Create Data Routes: GPIO_0, GPIO_1, GPIO_2, 4 Byte I2C Read

2. Create Timer Tasks to read each GPIO in Analog mode, perform the I2C Read every 200 ms

3. After Tasks are created, start timer, and start logging

4. A repeating task downloads the log once every 20 seconds. I configure the notification to let me know when the download is done

This flow runs fine for about 5 minutes, then my software hangs. The metawear R module seems to be in a weird state for a couple of connection attempts then it works fine. I've also had the metawear R enter a state where it is unable to log anything until I reinstall the firmware. I've tried using the clearEntries() method and disconnect, but this doesn't consistently fix anything.

FWIW, streaming the data works just fine, so it doesn't seem to be a bluetooth connection issue. I'd prefer to log and do a bulk download to try to optimize power. It seems like this might be an issue with the logging system because of my firmware redownload fix, since that would erase the Flash memory.

Has anyone experienced similar issues?

I could provide code snippets if it would help.

sonalideo

Yes, the memory is likely full and then all kind of strange things starts to happen for me at least. Is this caused by data starts overwriting fundamental parts of the board? To reduce the most of these strange freezes I try to empty the logs and disconnect the board every 5 min to clear the memory, but it's not a viable solution since in case the board is not in range for it's logs to be emptied it will crash the next time it will be emptied...

I think patching of the firmware/android code for the cases when the logs are full is needed. Also perhaps a setting for overwrite/don't overwrite the logs when full is needed?

Eric

It does look like you are filling up the flash memory given how much data you are logging and how frequently you are logging.  The nRF chip cannot clear the on board memory until the BTLE link is dropped so you need to disconnect every time you complete a download.

Again, the on board logging is meant for the times where you cannot be connected to your board.  It is also meant to store processed sensor data not high capacities of raw data as there is not that much on board memory.

sonalideo

Did more tests today with the logging and I experience the same problems as jgummeson. Using metawear c/1.1.0 firmware/android api 2.3.0

Storing in logs and downloading for a couple of times (also with disconnects every 5 min to avoid full logs) will sometimes result in that log data only is downloaded but the entries can't be processed and sometimes not even downloadable until a complete hardware reset is done. Just resetting the board from software with debugModule.resetDevice() does not solve this lock on the logs.

Also can't it be possible to just overwrite old data on the board without clearing it with a disconnect to reduce the issues with the logging?

Matt

@jgummeson : Could you confirm the version of the firmware and API are you running?  We made a many enhancements to the logger to improve robustness and reliability that were released in r1.1.0.

Your use case should work as expected, however downloading the log every 20 seconds is pretty aggressive time wise.  If you expect to be maintaining the radio connection, streaming would be a better option.  We have added endpoints to reduce the radio bandwidth, so you can match that to your data streaming rate to optimize power consumption.  Logging requires additional energy for NVM programs and erases, as well as increases the radio payload size by adding a timestamp to each data point.

As mentioned by others, in your flow you will need to disconnect occasionally to allow the logger to "garbage collect" flash blocks.  Unfortunately, it is not possible to perform an erase while in a connection. An erase operation takes considerable time, and no code can be executed while it is being performed which disrupts the radio communications.

@sonalideo : Strange things should not happen once the log is full.  The expected behavior is that new data entries will be dropped, because there is no where to put them.  On the next disconnect, it may be slower than usual to restart advertising if there are many blocks to recycle.  Full or empty, the board should not crash the next time you start a readout.  Can you provide a crash report and steps to reproduce?  We have many unit tests at the firmware and API level testing things such as filling it full, disconnecting during readout, etc.  But we can always use more if you have found a gap in our coverage.

Regarding data overwriting fundamental parts, the firmware has redundant checks to ensure that logger data cannot erase or overwrite code sections.  The logger itself has range checks before program and erase commands are issued, and the chip itself has memory segment protection configured at boot to protect the firmware and bootloader segments.

The logger is fully designed to handle the case where it is completely filled up.  If you are seeing crashes then it must be a corner case and we need to debug it.  The firmware already has "Circular Buffer Mode" which changes the full log behavior to drop some of the oldest data in the log and overwrite it -- however, the device cannot be held in a connection or it will be unable to perform an erase.

@sonalideo : Could you provide more details about your bug sighting in the latest post.  What do you mean that the data is downloaded but cannot processed?  If the data can be downloaded then the logger must be functioning properly -- at least for the readout.

DebugModule.resetDevice() does a complete power on reset of the firmware and system controller.  In nearly all cases this should be equivalent to a power cycle.

Unfortunately, it is not possible to overwrite data without disconnecting to erase it first.  The log data is stored in non volatile flash memory -- so that it persists, even through a power cycle.  Flash memory can physically only be programmed in one direction between erases.  If the application does not require long term storage and power cycle persistence it would be better to stream.

Matt

@jgummeson @sonalideo : Eric and I recreated the use case as best we could given the information we have, and we were not able to reproduce any crashes.

Lets start by confirming versions, and if we are all on the latest we will need more details to reproduce and then debug the issue.

sonalideo

Thanks for the investigation!

We have done more extensive tests also now and improved our code so that it is disconnecting immediately after 8000 of log entries downloaded. Also upgraded to v1.1.1 and API 2.4.0 (Android 4.4.2). The number of times it enters into this strange state has been significantly reduced and it mostly happens on one type of tablet hardware that we see also has issues with the bluetooth connection in general to the metawear board. (sets bluetooth in a non connectable state after a while even though it is indicated as on on the tablet and sending multiple disconnects events with no connect event in between from ConnectionStateHandler)

We will continue investigating it next week and see if we can reproduce this or if the upgrades have removed this limbo state.