mobizt / Firebase-ESP-Client

[DEPRECATED]🔥Firebase Arduino Client Library for ESP8266, ESP32 and RP2040 Pico. The complete, fast, secured and reliable Firebase Arduino client library that supports RTDB, Cloud Firestore, Firebase and Google Cloud Storage, Cloud Messaging and Cloud Functions for Firebase.
MIT License
471 stars 101 forks source link

Username & Password Refresh Token Issue in 4.3.x #461

Closed djmick closed 1 year ago

djmick commented 1 year ago

In versions 4.30 & 4.3.1 config.signer.preRefreshSeconds is not working with username & password authentication with RTDB. Then after 1 hour when the current token expires, config.token_status_callback is never called and i get permission denied errors. if i reboot, it works fine for the next hour.

If i rollback to V4.2.7, everything works as expected. I currently have config.signer.preRefreshSeconds to 3400 so the token refreshes after a couple of minutes.

To summarize, same code in 4.2.7 has no issue but when upgrading to 4.3.x, preRefreshSeconds doesn't work and after 1 hour i get access denied errors.

mobizt commented 1 year ago

It depends on how Firebase.ready() was called. It should run in main loop, if some of your code blocks the Firebase.ready() to run in that loop then the token will not refresh in time and expired.

If you set config.signer.preRefreshSeconds = 3600 - 60; the token will be expired in 1 minute.

I am running the test intensively all the time to make sure the library is working fine, and I don't see the issue on this.

mobizt commented 1 year ago

You should clean install the library to leave only one Firebase library in libraries folder, The manual zip installation and then using Arduino IDE Library Manager to update causes unexpected result at runtime due to the new version installed in folder "Firebase Arduino Client Library for ESP8266 and ESP32" while the manual zip installation stays in the folder "Firebase-ESP-Client-main" which is my fault in library properties file.

The problem occurred when compiler found the same file in multiples folders and choose the wrong old files for compilation

mobizt commented 1 year ago

I confirm that everything works fine as I currently testing. If you get some strange behavior in such key function of this library (authentication) after library updated, please clean install the library.

djmick commented 1 year ago

Yes Firebase.ready() is always being called.

I was running v4.2.7 and used the arduino library update feature to upgrade to 4.3.1. I complied the code and ran into the issues described. I then manually uninstalled 4.3.1 and installed 4.2.7 via arduino library install and then compiled. Same code started working.

The only thing i didn't do was install 4.3.1 from clean. I will try that now and follow up.

mobizt commented 1 year ago

The code in v4.3.x is almost completely rewrite for optimization which the file name was unchanged from v4.2.7 unless the code inside.

djmick commented 1 year ago

Here is my code i used for this test. Its using 4.3.1

`/**

include

// Provide the token generation process info.

include <addons/TokenHelper.h>

// Provide the RTDB payload printing info and other helper functions.

include <addons/RTDBHelper.h>

/ 1. Define the WiFi credentials /

define WIFI_SSID "xxxxx"

define WIFI_PASSWORD "xxxxx"

// For the following credentials, see examples/Authentications/SignInAsUser/EmailPassword/EmailPassword.ino

/ 2. Define the API Key /

define API_KEY "xxxxx"

/ 3. Define the RTDB URL /

define DATABASE_URL "xxxxx" //.firebaseio.com or ..firebasedatabase.app

/ 4. Define the user Email and password that alreadey registerd or added in your project /

define USER_EMAIL "xxxxx"

define USER_PASSWORD "xxxxx"

// Define Firebase Data object FirebaseData stream; FirebaseData fbdo;

FirebaseAuth auth; FirebaseConfig config;

unsigned long sendDataPrevMillis = 0;

int count = 0;

volatile bool dataChanged = false;

void streamCallback(FirebaseStream data) { printCurrentTime(false); Serial.println(" - Stream Callback"); Serial.printf("sream path, %s\nevent path, %s\ndata type, %s\nevent type, %s\n\n", data.streamPath().c_str(), data.dataPath().c_str(), data.dataType().c_str(), data.eventType().c_str()); printResult(data); // see addons/RTDBHelper.h Serial.println();

// This is the size of stream payload received (current and max value)
// Max payload size is the payload size under the stream path since the stream connected
// and read once and will not update until stream reconnection takes place.
// This max value will be zero as no payload received in case of ESP8266 which
// BearSSL reserved Rx buffer size is less than the actual stream payload.
Serial.printf("Received stream payload size: %d (Max. %d)\n\n", data.payloadLength(), data.maxPayloadLength());

// Due to limited of stack memory, do not perform any task that used large memory here especially starting connect to server.
// Just set this flag and check it status later.
dataChanged = true;

}

void streamTimeoutCallback(bool timeout) { printCurrentTime(false); Serial.println(" - Stream Timeout Callback"); if (timeout) Serial.println("stream timed out, resuming...\n");

if (!stream.httpConnected())
    Serial.printf("error code: %d, reason: %s\n\n", stream.httpCode(), stream.errorReason().c_str());

Serial.println();

}

void setup() {

Serial.begin(115200);

WiFi.begin(WIFI_SSID, WIFI_PASSWORD);
Serial.print("Connecting to Wi-Fi");
while (WiFi.status() != WL_CONNECTED)
{
    Serial.print(".");
    delay(300);
}
Serial.println();
Serial.print("Connected with IP: ");
Serial.println(WiFi.localIP());
Serial.println();

ntpInit(); //get time

Serial.printf("Firebase Client v%s\n\n", FIREBASE_CLIENT_VERSION);

/* Assign the api key (required) */
config.api_key = API_KEY;

/* Assign the user sign in credentials */
auth.user.email = USER_EMAIL;
auth.user.password = USER_PASSWORD;

/* Assign the RTDB URL (required) */
config.database_url = DATABASE_URL;

/* Assign the callback function for the long running token generation task */
config.token_status_callback = my_tokenStatusCallback; // see addons/TokenHelper.h

config.signer.preRefreshSeconds = 3600 - 120;

// Or use legacy authenticate method
// config.database_url = DATABASE_URL;
// config.signer.tokens.legacy_token = "<database secret>";

// To connect without auth in Test Mode, see Authentications/TestMode/TestMode.ino

Firebase.begin(&config, &auth);

Firebase.reconnectWiFi(true);

// Recommend for ESP8266 stream, adjust the buffer size to match your stream data size

if defined(ESP8266)

stream.setBSSLBufferSize(2048 /* Rx in bytes, 512 - 16384 */, 512 /* Tx in bytes, 512 - 16384 */);

endif

String fbUid = auth.token.uid.c_str();
String fbDbPath =  "/users/" + fbUid;
Serial.print("RTDB User Path: ");
Serial.println(fbDbPath);

if (!Firebase.RTDB.beginStream(&stream, fbDbPath + "/app"))
    Serial.printf("sream begin error, %s\n\n", stream.errorReason().c_str());

Firebase.RTDB.setStreamCallback(&stream, streamCallback, streamTimeoutCallback);

/** Timeout options, below is default config.

//WiFi reconnect timeout (interval) in ms (10 sec - 5 min) when WiFi disconnected.
config.timeout.wifiReconnect = 10 * 1000;

//Socket begin connection timeout (ESP32) or data transfer timeout (ESP8266) in ms (1 sec - 1 min).
config.timeout.socketConnection = 30 * 1000;

//ESP32 SSL handshake in ms (1 sec - 2 min). This option doesn't allow in ESP8266 core library.
config.timeout.sslHandshake = 2 * 60 * 1000;

//Server response read timeout in ms (1 sec - 1 min).
config.timeout.serverResponse = 10 * 1000;

//RTDB Stream keep-alive timeout in ms (20 sec - 2 min) when no server's keep-alive event data received.
config.timeout.rtdbKeepAlive = 45 * 1000;

//RTDB Stream reconnect timeout (interval) in ms (1 sec - 1 min) when RTDB Stream closed and want to resume.
config.timeout.rtdbStreamReconnect = 1 * 1000;

//RTDB Stream error notification timeout (interval) in ms (3 sec - 30 sec). It determines how often the readStream
//will return false (error) when it called repeatedly in loop.
config.timeout.rtdbStreamError = 3 * 1000;

*/

}

void loop() {

// Firebase.ready() should be called repeatedly to handle authentication tasks.

if defined(PICO_RP2040)

Firebase.RTDB.runStream();

endif

if (Firebase.ready() && (millis() - sendDataPrevMillis > 15000 || sendDataPrevMillis == 0))
{
    //sendDataPrevMillis = millis();
    //count++;
    //FirebaseJson json;
    //json.add("data", "hello");
    //json.add("num", count);
    //Serial.printf("Set json... %s\n\n", Firebase.RTDB.setJSON(&fbdo, "/test/stream/data/json", &json) ? "ok" : fbdo.errorReason().c_str());
}

if (dataChanged)
{
    dataChanged = false;
    // When stream data is available, do anything here...
}

}

void my_tokenStatusCallback(TokenInfo info) { /** fb_esp_auth_token_status enum

const char* ntpServer = "pool.ntp.org"; const long gmtOffset_sec = 18000; const int daylightOffset_sec = 3600;

define TZ "EST5EDT,M3.2.0,M11.1.0"

void ntpInit() { configTime(0, 0, ntpServer); // 0, 0 because we will use TZ in the next line setenv("TZ", TZ, 1); // Set environment variable with your time zone tzset();

//configTime(gmtOffset_sec, daylightOffset_sec, ntpServer);

time_t now;
struct tm timeinfo;

if (!getLocalTime(&timeinfo)) {
    Serial.println("Failed to obtain time");
}
else {
    Serial.println();
    Serial.println("--------------------");
    Serial.print("Current Boot Time (EDT): ");
    Serial.println(&timeinfo, "%a, %m/%d/%Y %I:%M:%S %p");
    Serial.println("--------------------");
    Serial.println();
}

}

void printCurrentTime(bool newLine) { time_t now; struct tm timeinfo;

//Firebase.getCurrentTime();
if (!getLocalTime(&timeinfo)) {
    Serial.println("Failed to obtain time");
    return;
}
else if (newLine) {
    Serial.println(&timeinfo, "%m/%d/%Y %I:%M:%S %p");
}
else {
    Serial.print(&timeinfo, "%m/%d/%Y %I:%M:%S %p");
}

}`

Here's a snapshot of the build image

And here is my serial output. As you can see based from line "Current Boot Time", almost 10 minutes went by without refreshing token that was schedule to be refreshed every 2 minutes.

Opening port Port open Connected with IP: 10.0.0.121


Current Boot Time (EDT): Sat, 01/07/2023 02:50:16 PM

Firebase Client v4.3.1


01/07/2023 02:50:16 PM Token info: type = id token (GITKit token), status = on request



01/07/2023 02:50:18 PM Token info: type = id token (GITKit token), status = ready


RTDB User Path: /users/MY_FIREBASE_USER_ID 01/07/2023 02:50:19 PM - Stream Timeout Callback stream timed out, resuming...

01/07/2023 02:50:20 PM - Stream Callback sream path, /users/MY_FIREBASE_USER_ID/app event path, / data type, json event type, put

Pretty printed JSON data: { "d1_alerts": { "ABCD": true }, "d1_displayName": "Door 1", "d1_enableLockFeature": true, "d1_isClosed": false, "d1_isHidden": false, "d1_isInverted": true, "d1_isLocked": false, "d2_alerts": { "ABCD": true }, "d2_displayName": "Door 2", "d2_enableLockFeature": true, "d2_isClosed": true, "d2_isHidden": false, "d2_isInverted": false, "d2_isLocked": false, "requests": { "-NLClvQnasXXGaqc0buo": { "doorId": 1, "requestType": "doorTrigger", "timeStamp": 1673120954132 } } } Iterate JSON data:

0, Type: object, Name: d1_alerts, Value: {"ABCD":true} 1, Type: object, Name: ABCD, Value: true 2, Type: object, Name: d1_displayName, Value: "Door 1" 3, Type: object, Name: d1_enableLockFeature, Value: true 4, Type: object, Name: d1_isClosed, Value: false 5, Type: object, Name: d1_isHidden, Value: false 6, Type: object, Name: d1_isInverted, Value: true 7, Type: object, Name: d1_isLocked, Value: false 8, Type: object, Name: d2_alerts, Value: {"ABCD":true} 9, Type: object, Name: ABCD, Value: true 10, Type: object, Name: d2_displayName, Value: "Door 2" 11, Type: object, Name: d2_enableLockFeature, Value: true 12, Type: object, Name: d2_isClosed, Value: true 13, Type: object, Name: d2_isHidden, Value: false 14, Type: object, Name: d2_isInverted, Value: false 15, Type: object, Name: d2_isLocked, Value: false 16, Type: object, Name: requests, Value: {"-NLClvQnasXXGaqc0buo":{"doorId":1,"requestType":"doorTrigger","timeStamp":1673120954132}} 17, Type: object, Name: -NLClvQnasXXGaqc0buo, Value: {"doorId":1,"requestType":"doorTrigger","timeStamp":1673120954132} 18, Type: object, Name: doorId, Value: 1 19, Type: object, Name: requestType, Value: "doorTrigger" 20, Type: object, Name: timeStamp, Value: 1673120954132

Received stream payload size: 780 (Max. 780)

01/07/2023 02:50:48 PM - Stream Callback sream path, /users/MY_FIREBASE_USER_ID/app event path, / data type, json event type, patch

Pretty printed JSON data: { "d1_isInverted": false } Iterate JSON data:

0, Type: object, Name: d1_isInverted, Value: false

Received stream payload size: 51 (Max. 780)

01/07/2023 02:51:18 PM - Stream Timeout Callback

01/07/2023 02:51:48 PM - Stream Timeout Callback

01/07/2023 02:52:18 PM - Stream Timeout Callback

01/07/2023 02:52:48 PM - Stream Timeout Callback

01/07/2023 02:53:18 PM - Stream Timeout Callback

01/07/2023 02:53:48 PM - Stream Timeout Callback

01/07/2023 02:54:18 PM - Stream Timeout Callback

01/07/2023 02:54:48 PM - Stream Timeout Callback

01/07/2023 02:55:18 PM - Stream Timeout Callback

01/07/2023 02:55:48 PM - Stream Timeout Callback

01/07/2023 02:56:18 PM - Stream Timeout Callback

01/07/2023 02:56:48 PM - Stream Timeout Callback

01/07/2023 02:57:18 PM - Stream Timeout Callback

01/07/2023 02:57:48 PM - Stream Timeout Callback

01/07/2023 02:58:18 PM - Stream Timeout Callback

01/07/2023 02:58:48 PM - Stream Timeout Callback

01/07/2023 02:59:18 PM - Stream Timeout Callback

01/07/2023 02:59:36 PM - Stream Callback sream path, /users/MY_FIREBASE_USER_ID/app event path, / data type, json event type, patch

Pretty printed JSON data: { "d2_isLocked": true } Iterate JSON data:

0, Type: object, Name: d2_isLocked, Value: true

Received stream payload size: 48 (Max. 780)

mobizt commented 1 year ago

Thanks for addressing this bug as it related to internal timestamp checking.

These lines cause the unchanged timestamp obtained from the getTime function. https://github.com/mobizt/Firebase-ESP-Client/blob/04eff0e3ad5713a3dac336b91ad389673c8ff4c9/src/FB_Utils.h#L1691-L1692

The library v4.3.2 is now available which fixed this bug, please update.

djmick commented 1 year ago

Thanks. I'm trying it now

djmick commented 1 year ago

So far everything seems to be working. Thank you for the prompt fix & updated release.