Weird log data from data sent by ESP32

[Uwe]

Hi,

I played around with the ESP32 example for Phyphox taken from here:
https://phyphox.org/wiki/index.php?title...ed_sensors

When I raised the frequency of notifications I found a surprising behaviour with time stamps logged in Phyphox and started to dig into that.
I modified the sketch so it sends the value of millis() (converted to 16bit int) every 5ms to my Samsung S6 running Phyphox app.
Here's the sketch used:

Code:

/*
//#############################################################################
//In this sketch a BLE server with one service and one characeristic is created.
//The analog input (pin 36) is readout periodically.

Diese Version dient dazu, zu testen, mit welcher Frequenz BLE Notifications an Phyphox verschickt werden können.
Dazu wird in einer Endlos-Schleife der jeweils aktuelle Wert von micros() gesendet.
In Phyphox kann man dann anhand der erhaltenen Werte sehen, mit welchem zeitlichen Abstand das erfolgt ist.

//#############################################################################
*/
#include <BLEDevice.h>
#include <BLEUtils.h>
#include <BLEServer.h>
#include <esp_system.h>
#include <BLE2902.h>


//uuid's can be generated on https://www.uuidgenerator.net/
//#define SERVICE_UUID        "cddf0001-30f7-4671-8b43-5e40ba53514a"
//#define CHARACTERISTIC_UUID "cddf0002-30f7-4671-8b43-5e40ba53514a"
#define SERVICE_UUID        "4fafc201-1fb5-459e-8fcc-c5c9c331914b"
#define CHARACTERISTIC_UUID "59f51a40-8852-4abe-a50f-2d45e6bd51ac"
BLECharacteristic *aCharacteristic;

uint16_t timestamp;

void setup() {
Serial.begin(115200);

//BLE server is being initialized
//create one BLEService and one Characteristic
BLEDevice::init("ESP32");
BLEServer *aServer = BLEDevice::createServer();
//uuid for the BLE service is set
BLEService *aService = aServer->createService(SERVICE_UUID);
//uuid for the BLE characteristic is set
//the characteristics properties are defined
aCharacteristic = aService->createCharacteristic(
                     CHARACTERISTIC_UUID,
                     BLECharacteristic::PROPERTY_READ   |
                     BLECharacteristic::PROPERTY_WRITE  |
                     BLECharacteristic::PROPERTY_NOTIFY 
                   );
aCharacteristic->addDescriptor(new BLE2902());

//BLE server is being started
aService->start();
BLEAdvertising *aAdvertising = aServer->getAdvertising();
aAdvertising->start();

}

void loop() {
timestamp = int(millis());
aCharacteristic->setValue(timestamp);
aCharacteristic->notify();
Serial.println(timestamp);
delay(5);

}

So each notification's value sent by ESP 32 increments by 5 and notification transmit interval is 5ms. No sensor used at all.
This allows to compare timing of GATT server and client (so I thought).

What I saw in Phyphox log was astonishing and up to now I have no idea what's going on:

1. When timestamps in Phyphox suggest that 1 sec has passed, only about 120 notifications (equivalent to 600 ms) arrived.
   This is a stable problem.
   
2. While timestamps logged show about 7-8 decimal places (which suggest a high resolution) values don't show a constant increase from entry to entry when one looks to decimals 2-8. Sometimes there is even the same timestamp for sequent entries !
   I know that anything more than 3-4 decimals doesn't make any sense, but if we cannot rely on decimal 2 than everything faster than 10Hz won't work.
   
3. Every 2 seconds the notification's value shows an instant increase of about 820 counts (= 820 ms = 160 notifications); so value of 2 sequent notifications differs by 820 counts
   It looks like as ESP32 has paused sending for a while; but at the same time there is NO gap in timestamps logged !!
   

With effects #1 and #3 combined timestamps and received values are in sync again after about 2 secs (600ms + 600ms + 820ms = 2000ms) , but nevertheless the behaviour seems to be strange and would mean a loss of data.
On ESP32 I added logging of millis() to serial monitor but didn't saw any pause or spontaneous increase of the value.

Good news is: this is not limited to Phyphox app; I also was able to see that behaviour e.g. with nRF connect app or LightBlue when logging data.
So it seems to be a BLE topic in general (may be in combination with Android).

I haven't tested other BLE connection parameters e.g. connection interval or others; even didn't set them explicitly at all, as I don't understand in detail (# packets per connection interval), so implicit default settings were used.

I've attached Excel sheet with log data from Phyphox' CSV export.

My questions:

1. Any idea where this might come from ? Anybody seen this or something similar before ?
   
2. Is frequency of notifications just to high (didn't test other intervals thoroughly) ?
   
3. Any hint how to proceed or solve ?
   

Thanks
Uwe