Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Aqara FP2: adding device doesn't work anymore #1648

Open
ldeora opened this issue Sep 25, 2024 · 32 comments
Open

Aqara FP2: adding device doesn't work anymore #1648

ldeora opened this issue Sep 25, 2024 · 32 comments

Comments

@ldeora
Copy link

ldeora commented Sep 25, 2024

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
@lelandblue
Copy link
Contributor

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.

@ldeora
Copy link
Author

ldeora commented Sep 25, 2024

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:

#1546

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

Can you please be more specific (which commit)?

@lelandblue
Copy link
Contributor

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.

@ldeora
Copy link
Author

ldeora commented Sep 25, 2024

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
Copy link
Author

ldeora commented Sep 27, 2024

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
Copy link
Author

ldeora commented Sep 29, 2024

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.

640f066

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
Copy link
Author

ldeora commented Sep 29, 2024

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
Copy link
Author

ldeora commented Oct 1, 2024

@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?

@seojune79
Copy link
Contributor

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.

@ldeora ldeora closed this as completed Oct 1, 2024
@ldeora
Copy link
Author

ldeora commented Oct 1, 2024

Thanks, @seojune79

@ldeora
Copy link
Author

ldeora commented Oct 17, 2024

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 ldeora reopened this Oct 17, 2024
@ldeora
Copy link
Author

ldeora commented Oct 17, 2024

@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.

@seojune79
Copy link
Contributor

seojune79 commented Oct 18, 2024

@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.

@ldeora
Copy link
Author

ldeora commented Oct 18, 2024

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
Copy link
Author

ldeora commented Oct 18, 2024

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

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

@ldeora
Copy link
Author

ldeora commented Oct 18, 2024

Make sure to read through the comments in this issue: #1654

@ldeora
Copy link
Author

ldeora commented Oct 18, 2024

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.

@seojune79
Copy link
Contributor

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

@ldeora
Copy link
Author

ldeora commented Oct 18, 2024

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
Copy link
Author

ldeora commented Oct 22, 2024

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

@hdlee27
Copy link
Contributor

hdlee27 commented Oct 22, 2024

@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.
#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.

@ldeora
Copy link
Author

ldeora commented Oct 22, 2024

@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

@hdlee27
Copy link
Contributor

hdlee27 commented Oct 22, 2024

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.

@ldeora
Copy link
Author

ldeora commented Oct 22, 2024

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.

@hdlee27
Copy link
Contributor

hdlee27 commented Oct 22, 2024

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

@hdlee27
Copy link
Contributor

hdlee27 commented Oct 22, 2024

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.
#1711
https://bestow-regional.api.smartthings.com/invite/kVlnxzapzLM4

@ldeora
Copy link
Author

ldeora commented Oct 22, 2024

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:

#1654 (comment)

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.

@hdlee27
Copy link
Contributor

hdlee27 commented Oct 22, 2024

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.

@ldeora
Copy link
Author

ldeora commented Oct 22, 2024

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
Copy link
Author

ldeora commented Oct 22, 2024

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
Copy link
Author

ldeora commented Oct 22, 2024

Food for thought: What would happen if the current production driver suddenly worked after the driver from this PR worked, which I will test later. That would mean that the cache and/or the fields would survive a delete/add. I don't know how persistent the fields are stored. The fields contain everything important for the adding to work.

local fields = {
  DEVICE_IPV4 = "device_ipv4",
  DEVICE_INFO = "device_info",
  CONN_INFO = "conn_info",
  EVENT_SOURCE = "eventsource",
  MONITORING_TIMER = "monitoring_timer",
  CREDENTIAL = "credential",
  _INIT = "init"
}

That would explain why some users don't have any issues at all. Users with the installed production version of the drivers who tried to add the device to ST the very first time. Not like those users who tried it before with the very first version from the PR!

What if deleting/adding works only for those who's device gets a different IP every 24 hours, invalidating the fields and/or cache, especially conn_info?

It still doesn't explain why the lunchbox rollback makes a difference or does it?

Just thinking out loud...

@ldeora
Copy link
Author

ldeora commented Oct 22, 2024

Sooo...

I tested it now back and forth:

Installed driver from PR (see above): works
Installed driver from main, production, beta: doesn't work
Installed driver from PR again: works
Installed driver from main, production, beta: doesn't work
Installed driver from PR again: works

Between driver changes, the exact same procedure: delete/add device in Aqara Home app, scan in ST.

In short: 2024-10-10 and 2024-10-21 doesn't work, 2024-10-22 works.

This is the proof that the lunchbox update broke the driver!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants