Intro
Using greengrass V2
aws.greengrass.ShadowManager
v2.2.1
aws.greengrass.Nucleus
v2.7.0
I built a custom component that talks to the shadowManager to update the device shadow. The shadowManager is configured as follow:
{
"strategy":{
"type":"realTime"
},
"synchronize":{
"coreThing":{
"classic":true,
"namedShadows":[
"notRelevant"
]
},
"direction":"betweenDeviceAndCloud"
}
}
The problem
My custom component attempts to do the following:
- Subscribe to
$aws/things/my_thing/shadow/delta/update
with callback function.
- Update device's
reported
values to some default values that's different from the desired
values in the IoT Core.
- The update in step 2 triggers the callback in step 1, which updates device's
reported
values with the desired
values.
I would expect the cloud to have matching desired
and reported
values at the end, but ended up with the default values inreported
, like so:
Where transmit_rate
15 and sample_rate
2.5 are the default values and the transmit_rate
10 and sample_rate
1 are the desired.
What I found
I checked our application software log and confirmed that two shadow update requests were made and accepted by the ShadowManager
. The first one updates the shadow to default values, and the second updates it to the desired values.
Then, I checked greengrass.log
and saw that the Updating sync info
logs highlighted seems to suggest that the two updates are synced in reserve order (version 278 first, with version 277 following). This appears to be highly correlated to the out-of-sync problem described above.
I was able to mitigate this problem by introducing a 1 second delay between the two update requests. This tells me that the problem might have to do with timing/synchronization within the ShadowManager
or the Greengrass Core software.
Does anyone have better idea on what the root cause can be?
Thanks,
---Edits ---
Adding a log from my custom component software to show the response from ShadowManager
(highlighted)
- the log on 09:26:00,112 is the response for my first
UpdateThingShadowRequest
- the next log on 09:26:00,112 is the
update/delta
shadow I received in the callback.
- the log on 09:26:00,122 is the response for my second
UpdateThingShadowRequest
Hey ictwist,
I have a few questions regarding what your component is doing to better understand your situation, given it is hard to tell how your application is structured with just the provided details:
You mention "Update device's reported values to some default values that's different from the desired values in the IoT Core.".
Does this mean you are starting by changing the
Device Shadow document
on IoT core through the aws console to some reported value or your custom component is changing the "reported" values, how are you doing this, what is the payload you are sending?Also you mention "the two updates are synced" so I am imagine either your custom component is sending 2 updates or is it that you start with a specific document value on the cloud and then when your component starts it tries to set it to something else? - Please provide more details about what your component is sending and what you are doing here
ochoanel,
Thanks for helping me to clarify:
UpdateThingShadowRequest
with the payload of$aws/things/my_thing/shadow/delta/update
What is the payload you are sending on your second request. I imagine you are calling
UpdateThingShadowRequest
, as you mentioned, after you get a call to the callback you registered on$aws/things/my_thing/shadow/delta/update
. Also just to double check, you are not manually modifying the document on the aws console correct? - Sorry for all the questions, just want to get the full picture to check if I can reproduce it myself and see what is going on.From the log picture you provided I can see the requests are being processed by different threads so it is possible that there might be a synchronization issue.
Yes the second update is also done through
UpdateThingShadowRequest
and the payload is thisYou are correct that this request is triggered by the callback I registered on
$aws/things/my_thing/shadow/delta/update
Since I can't figure out how to add image in comments, please see the edit part of my original post for additional log from my custom component that includes the responses from
ShadowManager
from my 2UpdateThingShadowRequest
calls.