SmartThingsEdgeDrivers icon indicating copy to clipboard operation
SmartThingsEdgeDrivers copied to clipboard
verified publisher icon SmartThingsCommunity

Aqara FP2: adding device doesn't work anymore

Open ldeora opened this issue 1 year ago • 32 comments

Edit: there's the problem:

2024-09-27T22:47:45.440063966Z ERROR Aqara Presence Sensor  get_credential : ip = 192.168.1.121, failed to get token, error = wantread
2024-09-27T22:47:45.445295882Z WARN Aqara Presence Sensor  credential is nil
2024-09-27T22:47:45.450356841Z ERROR Aqara Presence Sensor  failed to get credential. dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121

Can't add the device anymore! Removed the device, deleted the driver, added driver, tried to add the device. Tried it with main, beta, and PR channel to make sure.

It worked about a month ago. Since then, changes were made to discovery.lua, init.lua, device_manager.lua...

Can someone please check if adding the device still works?

Device firmware: 1.2.7_0011.0080 Hub firmware: 000.053.00019 ST app (Android): 1.8.18.21

Device works with the Aqara Home app.

This is the complete log and it looks like the driver lifecycle ends?

2024-09-25T10:34:03.597153457Z TRACE Aqara Presence Sensor  Setup driver aqara-fp2 with lifecycle handlers:
DeviceLifecycleDispatcher: aqara-fp2
  default_handlers:
    infoChanged:
    added:
    init:
    removed:
    driverSwitched:
  child_dispatchers:

2024-09-25T10:34:03.609944082Z TRACE Aqara Presence Sensor  Setup driver aqara-fp2 with Capability handlers:
CapabilityCommandDispatcher: aqara-fp2
  default_handlers:
    refresh:
      refresh
    multipleZonePresence:
      createZone
      deleteZone
      updateZoneName
  child_dispatchers:

2024-09-25T10:34:03.616156957Z INFO Aqara Presence Sensor  Created dispatcher [SecretDataDispatcher]aqara-fp2 that had no handlers
2024-09-25T10:34:03.628525582Z TRACE Aqara Presence Sensor  Setup driver aqara-fp2 with Secret Data handlers:
SecretDataDispatcher: aqara-fp2
  default_handlers:
  child_dispatchers:

2024-09-25T10:34:03.686260707Z TRACE Aqara Presence Sensor  Received event with handler driver_lifecycle
2024-09-25T10:34:03.707111916Z INFO Aqara Presence Sensor  received driver startupState: {"hub_zigbee_id":"KG2XAAILh00=","hub_node_id":1,"hub_ipv4":"192.168.1.116"}
2024-09-25T10:34:03.712373791Z TRACE Aqara Presence Sensor  Received event with handler discovery
2024-09-25T10:34:03.718594541Z INFO Aqara Presence Sensor  discovery_mdns.find_device_ips
2024-09-25T10:34:04.889382333Z INFO Aqara Presence Sensor  found_name = _Aqara-FP2._tcp
2024-09-25T10:34:04.941494333Z INFO Aqara Presence Sensor  ip = 192.168.1.109
2024-09-25T10:34:04.959243583Z INFO Aqara Presence Sensor  found_name = _Aqara-FP2._tcp
2024-09-25T10:34:04.972437916Z INFO Aqara Presence Sensor  ip = 192.168.1.109
2024-09-25T10:34:05.017133958Z TRACE Aqara Presence Sensor  unknown dni= 54:EF:44:5C:4C:98, ip= 192.168.1.109
2024-09-25T10:34:05.041282958Z TRACE Aqara Presence Sensor  try_add_device : dni= 54:EF:44:5C:4C:98, ip= 192.168.1.109
2024-09-25T10:34:05.075223208Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Creating TCP socket for REST Connection
2024-09-25T10:34:05.097121666Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Setting TCP socket timeout for REST Connection
2024-09-25T10:34:05.118858583Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Connecting TCP socket for REST Connection
2024-09-25T10:34:05.394824874Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Set Keepalive for TCP socket for REST Connection
2024-09-25T10:34:05.408426249Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Creating SSL wrapper for for REST Connection
2024-09-25T10:34:05.423615083Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Performing SSL handshake for for REST Connection
2024-09-25T10:34:07.962791666Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Successfully created TCP connection
2024-09-25T10:35:02.506882839Z TRACE Aqara Presence Sensor  Received event with handler discovery
2024-09-25T10:35:02.574833131Z TRACE Aqara Presence Sensor  Received event with handler driver_lifecycle

ldeora avatar Sep 25 '24 13:09 ldeora

Hey @ldeora - Thank you for reporting this issue. I am sorry for the inconvenience. SmartThings has recently introduced a new driver to support the Aqara FP2 device, and today we made a change that may resolve your issue.

Could you please delete your device and attempt to rejoin? If the issue persists, can you please share the device firmware version the FP2 device has?

Thank you for your time.

lelandblue avatar Sep 25 '24 15:09 lelandblue

The driver worked very well a month ago. When I came back from vacation I wanted to switch from the PR driver channel to main (or beta).

See my comment(s) here:

https://github.com/SmartThingsCommunity/SmartThingsEdgeDrivers/pull/1546

"today we made a change that may resolve your issue"

Can you please be more specific (which commit)?

ldeora avatar Sep 25 '24 17:09 ldeora

The change wasnt related to a commit made in the driver itself, it was elsewhere. The action we took was just to install the newly deployed LAN Aqara Presence Sensor driver on Hubs. It may take up to 24 hours for all hubs to get the change.

I would encourage you to wait 24 hours, then reattempt. Also, if the issue continues, please remember to report what version of firmware you have on your Aqara FP2 device.

lelandblue avatar Sep 25 '24 17:09 lelandblue

I'll try again tomorrow.

Device firmware: 1.2.7_0011.0080 Hub firmware: 000.053.00019 ST app (Android): 1.8.18.21

ldeora avatar Sep 25 '24 17:09 ldeora

Got a full log now.

The interesting part:

2024-09-27T22:47:45.440063966Z ERROR Aqara Presence Sensor  get_credential : ip = 192.168.1.121, failed to get token, error = wantread
2024-09-27T22:47:45.445295882Z WARN Aqara Presence Sensor  credential is nil
2024-09-27T22:47:45.450356841Z ERROR Aqara Presence Sensor  failed to get credential. dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121

Complete:

2024-09-27T22:46:40.619765579Z TRACE Aqara Presence Sensor  Setup driver aqara-fp2 with lifecycle handlers:
DeviceLifecycleDispatcher: aqara-fp2
  default_handlers:
    init:
    infoChanged:
    added:
    driverSwitched:
    removed:
  child_dispatchers:

2024-09-27T22:46:40.635536829Z TRACE Aqara Presence Sensor  Setup driver aqara-fp2 with Capability handlers:
CapabilityCommandDispatcher: aqara-fp2
  default_handlers:
    refresh:
      refresh
    multipleZonePresence:
      createZone
      updateZoneName
      deleteZone
  child_dispatchers:

2024-09-27T22:46:40.644384663Z INFO Aqara Presence Sensor  Created dispatcher [SecretDataDispatcher]aqara-fp2 that had no handlers
2024-09-27T22:46:40.705979413Z TRACE Aqara Presence Sensor  Setup driver aqara-fp2 with Secret Data handlers:
SecretDataDispatcher: aqara-fp2
  default_handlers:
  child_dispatchers:

2024-09-27T22:46:40.722801579Z TRACE Aqara Presence Sensor  Received event with handler driver_lifecycle
2024-09-27T22:46:40.727416621Z INFO Aqara Presence Sensor  received driver startupState: {"hub_zigbee_id":"KG2XAAILh00=","hub_node_id":1,"hub_ipv4":"192.168.1.116"}
2024-09-27T22:46:40.738916079Z TRACE Aqara Presence Sensor  Received event with handler discovery
2024-09-27T22:46:40.747689663Z INFO Aqara Presence Sensor  discovery_mdns.find_device_ips
2024-09-27T22:46:41.539953621Z INFO Aqara Presence Sensor  found_name = _Aqara-FP2._tcp
2024-09-27T22:46:41.551640830Z INFO Aqara Presence Sensor  ip = 192.168.1.121
2024-09-27T22:46:41.560703163Z INFO Aqara Presence Sensor  found_name = _Aqara-FP2._tcp
2024-09-27T22:46:41.566640538Z INFO Aqara Presence Sensor  ip = 192.168.1.121
2024-09-27T22:46:41.573283746Z TRACE Aqara Presence Sensor  unknown dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-09-27T22:46:41.577807538Z TRACE Aqara Presence Sensor  try_add_device : dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-09-27T22:46:41.582340580Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Creating TCP socket for REST Connection
2024-09-27T22:46:41.586796455Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Setting TCP socket timeout for REST Connection
2024-09-27T22:46:41.591843205Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Connecting TCP socket for REST Connection
2024-09-27T22:46:41.664880538Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Set Keepalive for TCP socket for REST Connection
2024-09-27T22:46:41.837995496Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Creating SSL wrapper for for REST Connection
2024-09-27T22:46:41.855930580Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Performing SSL handshake for for REST Connection
2024-09-27T22:46:45.358401372Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Successfully created TCP connection
2024-09-27T22:47:45.440063966Z ERROR Aqara Presence Sensor  get_credential : ip = 192.168.1.121, failed to get token, error = wantread
2024-09-27T22:47:45.445295882Z WARN Aqara Presence Sensor  credential is nil
2024-09-27T22:47:45.450356841Z ERROR Aqara Presence Sensor  failed to get credential. dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-09-27T22:47:45.742896591Z INFO Aqara Presence Sensor  discovery_mdns.find_device_ips
2024-09-27T22:47:47.004599132Z INFO Aqara Presence Sensor  found_name = _Aqara-FP2._tcp
2024-09-27T22:47:47.011283341Z INFO Aqara Presence Sensor  ip = 192.168.1.121
2024-09-27T22:47:47.021633716Z INFO Aqara Presence Sensor  found_name = _Aqara-FP2._tcp
2024-09-27T22:47:47.033793132Z INFO Aqara Presence Sensor  ip = 192.168.1.121
2024-09-27T22:47:47.038557632Z TRACE Aqara Presence Sensor  unknown dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-09-27T22:47:47.049819716Z TRACE Aqara Presence Sensor  try_add_device : dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-09-27T22:47:47.057299299Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Creating TCP socket for REST Connection
2024-09-27T22:47:47.080912716Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Setting TCP socket timeout for REST Connection
2024-09-27T22:47:47.089521132Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Connecting TCP socket for REST Connection
2024-09-27T22:47:47.116578299Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Set Keepalive for TCP socket for REST Connection
2024-09-27T22:47:47.353437341Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Creating SSL wrapper for for REST Connection
2024-09-27T22:47:47.397943758Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Performing SSL handshake for for REST Connection
2024-09-27T22:47:50.674634508Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Successfully created TCP connection
2024-09-27T22:48:50.803410432Z ERROR Aqara Presence Sensor  get_credential : ip = 192.168.1.121, failed to get token, error = wantread
2024-09-27T22:48:50.808347723Z WARN Aqara Presence Sensor  credential is nil
2024-09-27T22:48:50.813440682Z ERROR Aqara Presence Sensor  failed to get credential. dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-09-27T22:48:51.069608890Z INFO Aqara Presence Sensor  discovery_mdns.find_device_ips
2024-09-27T22:48:52.324482265Z INFO Aqara Presence Sensor  found_name = _Aqara-FP2._tcp
2024-09-27T22:48:52.332481599Z INFO Aqara Presence Sensor  ip = 192.168.1.121
2024-09-27T22:48:52.344583515Z INFO Aqara Presence Sensor  found_name = _Aqara-FP2._tcp
2024-09-27T22:48:52.355385765Z INFO Aqara Presence Sensor  ip = 192.168.1.121
2024-09-27T22:48:52.363825765Z TRACE Aqara Presence Sensor  unknown dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-09-27T22:48:52.368662640Z TRACE Aqara Presence Sensor  try_add_device : dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-09-27T22:48:52.381606974Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Creating TCP socket for REST Connection
2024-09-27T22:48:52.387539974Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Setting TCP socket timeout for REST Connection
2024-09-27T22:48:52.392373140Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Connecting TCP socket for REST Connection
2024-09-27T22:48:52.425812307Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Set Keepalive for TCP socket for REST Connection
2024-09-27T22:48:52.593265932Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Creating SSL wrapper for for REST Connection
2024-09-27T22:48:52.609604724Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Performing SSL handshake for for REST Connection
2024-09-27T22:48:55.814006016Z INFO Aqara Presence Sensor  54:EF:44:5C:4C:98 Successfully created TCP connection
2024-09-27T22:49:40.692051688Z TRACE Aqara Presence Sensor  Received event with handler discovery
2024-09-27T22:49:40.724452979Z TRACE Aqara Presence Sensor  Received event with handler driver_lifecycle

ldeora avatar Sep 27 '24 22:09 ldeora

I'm pretty sure now that the very last commit (the whole lunchbox updated to the latest version and more), right before the PR was merged into main broke the driver.

https://github.com/SmartThingsCommunity/SmartThingsEdgeDrivers/pull/1546/commits/640f0667a413440b9674c6adc6228d57c2f236fc

I was on vacation when I saw it and thought that this is quite a large change and this should be tested extensively. When I came back I just did that and yeah...

First I thought that the firmware has an expiration date for the REST GET /authcode - see get_credential(). Then I thought that the SSL certificate has been replaced for the next firmware update, but it's the same. The log confirms that the SSL/TCP/HTTPS connection is successfully established.

There's a change from Request to HttpMessage, function recv_additional_response(original_response, sock) has been removed completely and this could be the culprit, because in the luasec documentation it says that wantread is also a response to an incomplete response. And so on...

Quite a lot of changes to break the REST communication with the FP2 REST API and get_credential is the very first call, from what I can see.

Or maybe the SSL connection dies right before or in the middle of the first request.

I might be wrong but there were absolutely no changes on my side: same firmware (device, hub), only after the commit, I can't re-add the device.

ldeora avatar Sep 29 '24 22:09 ldeora

Thanks, ChatGPT!

The "wantread" error in luasec (a Lua library for SSL/TLS support) typically indicates that a non-blocking operation is expected to read more data from the network (e.g., receiving SSL/TLS data) but hasn't yet completed. It usually happens in a context where the underlying socket or connection isn't ready to read data immediately.

In simpler terms, the socket is telling you that it wants more time to read data, and your program needs to try again later. This is common in non-blocking or asynchronous networking operations, where the program doesn't stop and wait for an operation to finish.

Possible solutions:

  1. Use ssl.wrap with blocking I/O: If you're working with a blocking socket, ensure that your socket is blocking so it waits for the data to come in.

  2. Check the socket readiness: If you're using non-blocking I/O, you may need to use a select mechanism (like socket.select) to check if the socket is ready for reading before you try to read from it.

Example:

local readable, _, _ = socket.select({sock}, nil, timeout)
if readable then
    -- Now safe to read from 'sock'
end
  1. Handle the error gracefully: When you get the "wantread" error, it may be appropriate to handle it by retrying the read operation after a small delay or using non-blocking I/O effectively.

By dealing with the "wantread" error properly, you can ensure your program handles networking more smoothly without blocking or failing unexpectedly.

The "wantread" message is not specific to luasec alone but is commonly associated with Lua's socket library (specifically luasocket), which is often used for non-blocking network operations.

In the context of luasocket, the wantread message indicates that the socket is not ready to read data yet and the operation should be retried later. This happens in non-blocking mode when you're trying to read data from a socket, but the data isn't available at that moment.

Where it's seen:

luasocket: In non-blocking socket operations, the "wantread" message is returned when trying to perform a read operation on a socket that is not yet ready to provide data.

luasec: Since luasec builds on top of luasocket for SSL/TLS connections, you may encounter the same wantread behavior if the SSL/TLS connection is waiting to be able to read more data.

In summary:

luasocket commonly returns "wantread" during non-blocking I/O operations.

luasec, being built on luasocket, inherits this behavior when using non-blocking SSL/TLS connections.

In both cases, the solution generally involves checking the readiness of the socket using a select mechanism (like socket.select), or adjusting the socket to blocking mode if non-blocking is not required.

ldeora avatar Sep 29 '24 22:09 ldeora

@seojune79 Is there a reason why the FP2 can't be added anymore? Maybe a hidden expiration date for /authcode or the whole REST in firmware version 1.2.7_0011.0080?

ldeora avatar Oct 01 '24 18:10 ldeora

If something goes wrong while removing FP2 from the ST app, the device won't be onboarded. If this happens, removing and onboarding the FP2 in the Aqara home app and then trying to onboard in the ST app should resolve the issue.

seojune79 avatar Oct 01 '24 23:10 seojune79

Thanks, @seojune79

ldeora avatar Oct 01 '24 23:10 ldeora

Not fixed. Another user has the same issue. Read the comments here (conversation between Andreas_Roedl and ewimer2):

https://community.smartthings.com/t/aqara-fp2-tested-with-smartthings/270688/136

User has hub firmware 54.x, FP2 firmware 1.2.8x.

Keep in mind that the rollout of the FP2 firmware isn't completed yet and these are the first users who are trying to connect the FP2 to ST.

ldeora avatar Oct 17 '24 11:10 ldeora

@seojune79

If something goes wrong while removing FP2 from the ST app, the device won't be onboarded. If this happens, removing and onboarding the FP2 in the Aqara home app and then trying to onboard in the ST app should resolve the issue.

Doesn't seem to work for some users.

ldeora avatar Oct 17 '24 11:10 ldeora

@seojune79

If something goes wrong while removing FP2 from the ST app, the device won't be onboarded. If this happens, removing and onboarding the FP2 in the Aqara home app and then trying to onboard in the ST app should resolve the issue.

Doesn't seem to work for some users.

Can you check if FP2 and SmartThings hub are connected to the same network? I think it is necessary to check the IP of those devices.

seojune79 avatar Oct 18 '24 00:10 seojune79

This is from the logcat of the user:

2024-10-16T00:28:57.487769932Z INFO Aqara Presence Sensor 54:EF:44:5B:E4:1F Successfully created TCP connection
2024-10-16T00:29:58.667069064Z ERROR Aqara Presence Sensor get_credential : ip = 192.168.86.52, failed to get token, error = wantread
2024-10-16T00:29:58.669291523Z WARN Aqara Presence Sensor credential is nil
2024-10-16T00:29:58.689109731Z ERROR Aqara Presence Sensor failed to get credential. dni= 54:EF:44:5B:E4:1F, ip= 192.168.86.52

Connection established.

ldeora avatar Oct 18 '24 00:10 ldeora

More and more users report that it doesn't work:

https://community.smartthings.com/t/aqara-fp2-tested-with-smartthings/270688/176

ldeora avatar Oct 18 '24 00:10 ldeora

Make sure to read through the comments in this issue: https://github.com/SmartThingsCommunity/SmartThingsEdgeDrivers/issues/1654

ldeora avatar Oct 18 '24 00:10 ldeora

Looks like the REST API isn't (correctly) activated, despite having the device added to the Aqara Home app / cloud. I had the same problem, but after removing and onboarding it, it worked. At least two users now report that even that doesn't work.

If I remember correctly, the first request is a GET /authcode and this fails. Haven't looked at the code since weeks.

ldeora avatar Oct 18 '24 01:10 ldeora

I am attaching the procedure, video, and logcat that I tested, so please check it

recorded screen 20sec: onboarding fail in ST app 26sec: remove fp2 in Aqara app 32sec: onboarding fpr2 in Aqara app( fp2 reset required -> press and hold the reset button for more than 10 seconds ) 1min 22sec: onboarding in ST app 1min 43sec: success logcat.txt

seojune79 avatar Oct 18 '24 01:10 seojune79

Going to communicate that to the affected users and give feedback here.

Thanks.

FYI: they tried all that multiple times without success. I'll make sure that they reset the device correctly.

ldeora avatar Oct 18 '24 01:10 ldeora

I can replicate this issue here with the driver from the original PR, the production and the beta driver.

Here's the log that is pretty much identical to the logs from other people with the same problem:

2024-10-22T00:56:29.144965610Z TRACE Aqara Presence Sensor Setup driver aqara-fp2 with lifecycle handlers:
DeviceLifecycleDispatcher: aqara-fp2
  default_handlers:
    infoChanged:
    init:
    driverSwitched:
    removed:
    added:
  child_dispatchers:

2024-10-22T00:56:29.147693598Z TRACE Aqara Presence Sensor Setup driver aqara-fp2 with Capability handlers:
CapabilityCommandDispatcher: aqara-fp2
  default_handlers:
    multipleZonePresence:
      createZone
      deleteZone
      updateZoneName
    refresh:
      refresh
  child_dispatchers:

2024-10-22T00:56:29.149793481Z INFO Aqara Presence Sensor Created dispatcher [SecretDataDispatcher]aqara-fp2 that had no handlers
2024-10-22T00:56:29.158295438Z TRACE Aqara Presence Sensor Setup driver aqara-fp2 with Secret Data handlers:
SecretDataDispatcher: aqara-fp2
  default_handlers:
  child_dispatchers:

2024-10-22T00:56:29.162515714Z TRACE Aqara Presence Sensor Received event with handler environment_info
2024-10-22T00:56:29.165943719Z TRACE Aqara Presence Sensor Received event with handler environment_info
2024-10-22T00:56:29.168631020Z DEBUG Aqara Presence Sensor Z-Wave hub node ID environment changed.
2024-10-22T00:56:29.172345627Z TRACE Aqara Presence Sensor Received event with handler environment_info
2024-10-22T00:56:29.178248035Z TRACE Aqara Presence Sensor Received event with handler discovery
2024-10-22T00:56:29.182683751Z TRACE Aqara Presence Sensor Received event with handler driver_lifecycle
2024-10-22T00:56:29.184981066Z INFO Aqara Presence Sensor received driver startupState: {"hub_zigbee_id":"KG2XAAILh00=","hub_node_id":1,"hub_ipv4":"192.168.1.116"}
2024-10-22T00:56:29.192462180Z INFO Aqara Presence Sensor discovery_mdns.find_device_ips
2024-10-22T00:56:30.493928505Z INFO Aqara Presence Sensor found_name = _Aqara-FP2._tcp
2024-10-22T00:56:30.504129019Z INFO Aqara Presence Sensor ip = 192.168.1.121
2024-10-22T00:56:30.504909117Z INFO Aqara Presence Sensor found_name = _Aqara-FP2._tcp
2024-10-22T00:56:30.505597503Z INFO Aqara Presence Sensor ip = 192.168.1.121
2024-10-22T00:56:30.511888438Z TRACE Aqara Presence Sensor unknown dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-10-22T00:56:30.515899693Z TRACE Aqara Presence Sensor try_add_device : dni= 54:EF:44:5C:4C:98, ip= 192.168.1.121
2024-10-22T00:56:30.516701010Z INFO Aqara Presence Sensor 54:EF:44:5C:4C:98 Creating TCP socket for REST Connection
2024-10-22T00:56:30.553897683Z INFO Aqara Presence Sensor 54:EF:44:5C:4C:98 Setting TCP socket timeout for REST Connection
2024-10-22T00:56:30.555842405Z INFO Aqara Presence Sensor 54:EF:44:5C:4C:98 Connecting TCP socket for REST Connection
2024-10-22T00:56:30.608109483Z INFO Aqara Presence Sensor 54:EF:44:5C:4C:98 Set Keepalive for TCP socket for REST Connection
2024-10-22T00:56:30.611883911Z INFO Aqara Presence Sensor 54:EF:44:5C:4C:98 Creating SSL wrapper for for REST Connection
2024-10-22T00:56:30.797716489Z INFO Aqara Presence Sensor 54:EF:44:5C:4C:98 Performing SSL handshake for for REST Connection
2024-10-22T00:56:33.581176024Z INFO Aqara Presence Sensor 54:EF:44:5C:4C:98 Successfully created TCP connection
2024-10-22T00:57:26.030374607Z TRACE Aqara Presence Sensor Received event with handler discovery
2024-10-22T00:57:26.095867837Z TRACE Aqara Presence Sensor Received event with handler driver_lifecycle

That's all. These warnings and errors from previous versions are gone:

2024-10-16T00:28:57.487769932Z INFO Aqara Presence Sensor 54:EF:44:5B:E4:1F Successfully created TCP connection
2024-10-16T00:29:58.667069064Z ERROR Aqara Presence Sensor get_credential : ip = 192.168.86.52, failed to get token, error = wantread
2024-10-16T00:29:58.669291523Z WARN Aqara Presence Sensor credential is nil
2024-10-16T00:29:58.689109731Z ERROR Aqara Presence Sensor failed to get credential. dni= 54:EF:44:5B:E4:1F, ip= 192.168.86.52

Since there's no real logging in the driver to see if there's even an attempt to get the auth token, it's impossible to debug.

Several users tried everything over the curse of a week now. Deleted the device everywhere, reset everything, tried every available driver version. It would be helpful if you would explain why it is necessary to remove the device from the Aqara Home app and re-add it, @seojune79 . Does it activate the REST API?

I've read through the code a dozen times and I'm on my wits end.

BTW: the mdns discovery doesn't even work on TV hubs, driver isn't started, but that's a different issue.

Read this thread from bottom up to see that we tried everything:

https://community.smartthings.com/t/aqara-fp2-tested-with-smartthings/270688/235

Does anybody care at all if it works? And no, code reviews and "LGTM" is NOT enough - these are drivers that deal with and should be tested with real world devices. Deleting and adding the device, testing the functionality after every single commit.

(I'm starting to believe that it only works in bright daylight because the illuminance sensor is involved in creating the auth token... or something like that...)

Tagging, @lelandblue @FreeMasen @cjswedes

ldeora avatar Oct 22 '24 01:10 ldeora

@ldeora Hello, I will write down what I understand as much as possible.

FP2 basically does not generate additional credentials once it generates credentials. In order to generate the credential again, the following method is required.

  1. Reset when initialized with button long press
  2. Reset if erased from aqara app
  3. (When the driver has the credential well) Delete it from the smartthings app

if a problem occurs, method 3 cannot be used and reset through 1 or 2 is required.

And, in the case below, onboarding may fail. case A. When onboarding is attempted in the version before hub 54.0011 case B. If this device is created after credential creation and lost before set filed completion

in the case of A, I understand that @cjswedes has already solved it. in the case of B, As far as I know, the modified PR has been merged, and the driver with this has not been released yet. https://github.com/SmartThingsCommunity/SmartThingsEdgeDrivers/pull/1685

if onboarding fails once due to the case of a or b, onboarding is not possible again until initialization because the credential has already been issued. And if the user presses back without waiting enough when onboarding again after reset, the credential may be lost again. For those who fail to reset and retry, I suspect that it is because they have already pressed back too quickly in 'search near by' after reset due to their experience of failure.

The guides that can be done at the moment are as follows:

  1. Please clarify the reset
  2. Please 'search near by' in smartthings. At this time, do not press the back button for enough time and wait until the device is added.

hdlee27 avatar Oct 22 '24 05:10 hdlee27

@hdlee27

Thanks for the clarification.

  1. Can we agree that the onboarding process should be more straightforward?
  2. The logging in the driver is pretty much useless as it is - see my logs.
  3. I've tested the very latest version (2024-10-21T19:30) with the changes regarding the credentials management and of course I read the code and I wondered what would happen if the cache has invalid data. Is there a mechanism to clear the cache?
  4. Users affected stopped pressing the back button while "search nearby" a long time ago. Why? Because we are collecting logs every time.
  5. I've been testing this driver from the start with the very first PR. I was able to remove and add the device without problems but this doesn't work anymore. Something must have changed in the meantime - and I am still not convinced that it wasn't the last commit in the original PR that updated the lunchbox.
  6. Again: "LGTM" is not the same as "tested this commit with the device and it works!".
  7. If someone like me has problems with a WWST device, maybe it shouldn't be certified.
  8. We don't know how many people out there have the same issue but it doesn't look good... There wasn't a real public beta test. I doubt that everyone involved in development, code review, testing and the certification process even has an FP2.
  9. Did I mention that the driver isn't even started on TV hubs because the device isn't discovered by mDNS at all? Weird that nobody tested it on TV hubs - "Hubs everywhere"! Logs here: https://community.smartthings.com/t/aqara-fp2-tested-with-smartthings/270688/188

ldeora avatar Oct 22 '24 09:10 ldeora

Dear @ldeora

Your opinion is correct as a whole. There was a problem. I'm terribly sorry. It's my fault and I'd like to correct it now. Can you help me to fix it?

Is the problem reproduced in very latest version (2024-10-21T19:30)? I'm really sorry, but there is no problem when attaching fp2 to my v3 and smartthings station. I wonder if it depends on the user environment.

the problem that mdns is not found on TV seems to need further analysis.

hdlee27 avatar Oct 22 '24 10:10 hdlee27

Is the problem reproduced in very latest version (2024-10-21T19:30)?

See my comment above... (Nr. 3 in my list) sigh

I wonder if it depends on the user environment.

I'd guess that the environments of the affected users are very different but almost identical at the same time - different set of devices, but the same V3 hub with the same firmware and the same FP2 with the same firmware. Network works of course - see the logs: TCP connection established.

ldeora avatar Oct 22 '24 10:10 ldeora

Dear @ldeora I'm sorry. I didn't know it was tested with 2024-10-21T19:30

hdlee27 avatar Oct 22 '24 10:10 hdlee27

Dear @ldeora Could you check if it is normal onboarding with the driver below? This is a pr that uses the lunchbox of the initial version of the first pr You may be tired because you have already repeated it countless times, but please reset it again and onboard it. https://github.com/SmartThingsCommunity/SmartThingsEdgeDrivers/pull/1711 https://bestow-regional.api.smartthings.com/invite/kVlnxzapzLM4

hdlee27 avatar Oct 22 '24 10:10 hdlee27

THIS WORKS!!!

Screenshot_20241022_131006_SmartThings

See channel and version string:

Screenshot_20241022_131047_SmartThings

And you know what? That's what I was trying to tell everyone involved: the latest commit that updated the lunchbox broke the driver! Here just one example:

https://github.com/SmartThingsCommunity/SmartThingsEdgeDrivers/issues/1654#issuecomment-2385241234

And if I remember correctly several times right after the commit!

So now we have to create a diff between the current version and the one that works for me.

I'd do it, clone/branch the driver, add some more logging and so one, but I realized that I don't work for Samsung, SmartThings or Aqara and I'm not getting paid for it - quite the opposite: I paid for the device and spent countless hours to debug the driver.

To summarize: roll back the lunchbox update, do some rebasing to include the important changes/commits.

ldeora avatar Oct 22 '24 11:10 ldeora

Dear @ldeora Thank you very much for your confirmation and we will try to reflect this as soon as possible. And again, I'm terribly sorry.

hdlee27 avatar Oct 22 '24 11:10 hdlee27

Just send me the upcoming Aqara Light Switch H2 EU (no neutral) for all the troubles...

In the meantime I'll try to convince the other affected users to try the working version (lunchbox rollback), but I think they are fed up by now.

ldeora avatar Oct 22 '24 11:10 ldeora

BTW: reports are coming in increasingly that the current production driver doesn't work:

I am stuck on the “prepare your device” page within SmartThings app even after the following: Installing the Aqara FP2 driver Updating the FP2 firmware to 1.2.8 Removing and readding the device in Aqara Home app

https://community.smartthings.com/t/aqara-fp2-tested-with-smartthings/270688/239

On the other hand, there are reports that it works out of the box...

ldeora avatar Oct 22 '24 12:10 ldeora