[DataStorage] can not find device in cache

[tiokim]

Describe the bug
The edge-orchestration can not find the device in the cache if edge-orchestration registers device configuration to edgex for the first time. It works after reboot.

To Reproduce

1. Clear redis database
2. Run edge-orchestration with DataStorage configuration files
3. Call an API in terms of uploading Int value

• ex) curl -X POST "localhost:49986/api/v1/resource/datastorage/int" -H "accept: text/plain" -H "Content-Type: text/plain" -d 123

Log from edge-orchestration

level=INFO ts=2021-06-08T11:09:41.747141457Z app=datastorage source=config.go:193 msg="Loaded configuration from ./res/configuration.toml"

level=INFO ts=2021-06-08T11:09:41.748290804Z app=datastorage source=config.go:304 msg="Using local configuration from file (0 envVars overrides applied)"
level=INFO ts=2021-06-08T11:09:41.748336679Z app=datastorage source=httpserver.go:99 msg="Web server starting (127.0.0.1:49986)"
level=INFO ts=2021-06-08T11:09:41.748393149Z app=datastorage source=init.go:144 msg="Check Metadata service's status by ping..."
level=INFO ts=2021-06-08T11:09:41.748528479Z app=datastorage source=init.go:144 msg="Check Data service's status by ping..."
level=INFO ts=2021-06-08T11:09:41.749614627Z app=datastorage source=init.go:68 msg="Service clients initialize successful."
level=INFO ts=2021-06-08T11:09:41.750747311Z app=datastorage source=service.go:207 msg="Addressable datastorage doesn't exist, creating a new one"
level=DEBUG ts=2021-06-08T11:09:41.751916563Z app=datastorage source=service.go:153 msg="Trying to find DeviceService: datastorage"
level=INFO ts=2021-06-08T11:09:41.752643978Z app=datastorage source=service.go:157 msg="DeviceService datastorage doesn't exist, creating a new one"
level=DEBUG ts=2021-06-08T11:09:41.754344754Z app=datastorage source=service.go:169 msg="New DeviceService Id: 6faac9ac-6ec1-41ee-8661-927954bb7ea1"
INFO[2021-06-08T11:09:41Z]storagedriver.go:43 Initialize [storagedriver] Device service intialize started
level=DEBUG ts=2021-06-08T11:09:41.75790956Z app=datastorage source=restrouter.go:119 route=/api/v1/resource/{deviceName}/{resourceName} methods=[POST] msg="Route added"
level=INFO ts=2021-06-08T11:09:41.757963324Z app=datastorage source=storagehandler.go:66 msg="Route /api/v1/resource/{deviceName}/{resourceName} added."
level=INFO ts=2021-06-08T11:09:41.759800964Z app=datastorage source=restrouter.go:75 msg="Registering v2 routes..."
level=DEBUG ts=2021-06-08T11:09:41.76021791Z app=datastorage source=profiles.go:47 msg="created absolute path for loading pre-defined Device Profiles: /edge-orchestration/res"
level=DEBUG ts=2021-06-08T11:09:41.76330122Z app=datastorage source=profiles.go:172 msg="Getting EnableValueDescriptorManagement configuration value from Core Metadata"
level=DEBUG ts=2021-06-08T11:09:41.763993203Z app=datastorage source=devices.go:29 msg="Loading pre-define Devices from configuration"
level=DEBUG ts=2021-06-08T11:09:41.764037017Z app=datastorage source=devices.go:35 msg="Device datastorage doesn't exist, creating a new one"
level=DEBUG ts=2021-06-08T11:09:41.764581907Z app=datastorage source=devices.go:75 msg="Adding Device: {\"origin\":1623150581764,\"description\":\"RESTful Device\",\"name\":\"datastorage\",\"adminState\":\"UNLOCKED\",\"operatingState\":\"ENABLED\",\"protocols\":{\"other\":{}},\"labels\":[\"rest\",\"json\"],\"service\":{\"origin\":1623150581751,\"id\":\"6faac9ac-6ec1-41ee-8661-927954bb7ea1\",\"name\":\"datastorage\",\"operatingState\":\"ENABLED\",\"addressable\":{\"origin\":1623150581749,\"id\":\"7b016ca7-5b53-4aa3-88e5-6f4a0b484271\",\"name\":\"datastorage\",\"protocol\":\"HTTP\",\"method\":\"POST\",\"address\":\"127.0.0.1\",\"port\":49986,\"path\":\"/api/v1/callback\",\"baseURL\":\"http://127.0.0.1:49986\",\"url\":\"http://127.0.0.1:49986/api/v1/callback\"},\"adminState\":\"UNLOCKED\"},\"profile\":{\"description\":\"REST Device\",\"id\":\"3b356db4-fe39-4dc4-bd25-8bebef5e15ce\",\"name\":\"datastorage\",\"manufacturer\":\"Home Edge\",\"model\":\"Home Edge\",\"labels\":[\"rest\",\"json\",\"numeric\",\"float\",\"int\"],\"deviceResources\":[{\"description\":\"json\",\"name\":\"json\",\"properties\":{\"value\":{\"type\":\"String\",\"readWrite\":\"RW\",\"mediaType\":\"application/json\"},\"units\":{\"type\":\"String\",\"readWrite\":\"R\"}}},{\"name\":\"int\",\"properties\":{\"value\":{\"type\":\"Int64\",\"readWrite\":\"RW\",\"mediaType\":\"text/plain\"},\"units\":{\"type\":\"String\",\"readWrite\":\"R\"}}},{\"description\":\"float\",\"name\":\"float\",\"properties\":{\"value\":{\"type\":\"Float64\",\"readWrite\":\"RW\",\"mediaType\":\"text/plain\"},\"units\":{\"type\":\"String\",\"readWrite\":\"R\"}}},{\"description\":\"jpeg\",\"name\":\"jpeg\",\"properties\":{\"value\":{\"type\":\"Binary\",\"readWrite\":\"RW\",\"mediaType\":\"image/jpeg\"},\"units\":{\"type\":\"String\",\"readWrite\":\"R\"}}},{\"description\":\"png\",\"name\":\"png\",\"properties\":{\"value\":{\"type\":\"Binary\",\"readWrite\":\"RW\",\"mediaType\":\"image/png\"},\"units\":{\"type\":\"String\",\"readWrite\":\"R\"}}},{\"description\":\"string\",\"name\":\"string\",\"properties\":{\"value\":{\"type\":\"String\",\"readWrite\":\"RW\",\"mediaType\":\"text/plain\"},\"units\":{\"type\":\"String\",\"readWrite\":\"R\"}}}]}}"
level=INFO ts=2021-06-08T11:09:41.766971106Z app=datastorage source=autodiscovery.go:32 msg="AutoDiscovery stopped: disabled by configuration"
level=INFO ts=2021-06-08T11:09:41.767031297Z app=datastorage source=autodiscovery.go:37 msg="AutoDiscovery stopped: interval error in configuration"
level=INFO ts=2021-06-08T11:09:41.76706353Z app=datastorage source=autodiscovery.go:41 msg="AutoDiscovery stopped: ProtocolDiscovery not implemented"
level=INFO ts=2021-06-08T11:09:41.767094873Z app=datastorage source=message.go:50 msg="Service dependencies resolved..."
level=INFO ts=2021-06-08T11:09:41.767156624Z app=datastorage source=message.go:51 msg="Starting datastorage to be replaced by makefile "
level=INFO ts=2021-06-08T11:09:41.767182718Z app=datastorage source=message.go:58 msg="Service started in: 20.913936ms"


level=DEBUG ts=2021-06-08T11:09:51.973581107Z app=datastorage source=storagehandler.go:84 msg="Received POST for Device=datastorage Resource=int"
level=INFO ts=2021-06-08T11:09:51.973670443Z app=datastorage source=manageddevices.go:71 msg="Device datastorage cannot be found in cache"
level=ERROR ts=2021-06-08T11:09:51.973714012Z app=datastorage source=storagehandler.go:88 msg="Incoming reading ignored. Device 'datastorage' not found"

Test environment configuration (please complete the following information):

• Firmware version: Ubuntu 20.04
• Hardware: x86-64
• Edge Orchestration Release: Coconut

[sun-sharma]

Hi @t25kim,

I replicated the bug. This is happening whenever we try to add a new device also.

Example :

1. If we edit name of the YAML profile
2. Edit the name of Device in the config file

This device would not be discovered until we build for the second time. I tried this multiple times and this issue seems to be consistent. I am checking if this was a problem with the Hanoi release or if it needs to be done from our side.

[tiokim]

Hi @t25kim,

I replicated the bug. This is happening whenever we try to add a new device also.

Example :

1. If we edit name of the YAML profile
2. Edit the name of Device in the config file

This device would not be discovered until we build for the second time. I tried this multiple times and this issue seems to be consistent. I am checking if this was a problem with the Hanoi release or if it needs to be done from our side.

Thanks @sun-sharma.
I had the same problem with EdgeX v2.0.0. Please test it with the PR #326.

[nitu-s-gupta]

This issue is from EdgeX side, Whenevr the service is started the devices already present in metadata are loaded in cache. But the devices which are added are not addded to cache. Hence this doesnot occur after reboot. I have tried with device-rest.go. Observed the same behaviour. Changes are required in device-sdk of edgex foundry. Files i checked (/internal/provision/devices.go) of device sdk if edgexfoundry. This is called at device startup.

[MoonkiHong]

This issue is from EdgeX side, Whenevr the service is started the devices already present in metadata are loaded in cache. But the devices which are added are not addded to cache. Hence this doesnot occur after reboot. I have tried with device-rest.go. Observed the same behaviour. Changes are required in device-sdk of edgex foundry. Files i checked (/internal/provision/devices.go) of device sdk if edgexfoundry. This is called at device startup.

@nitu-s-gupta What about approaching to EdgeX with me and try resolving this issue? 😄

[tiokim]

This issue is from EdgeX side, Whenevr the service is started the devices already present in metadata are loaded in cache. But the devices which are added are not addded to cache. Hence this doesnot occur after reboot. I have tried with device-rest.go. Observed the same behaviour. Changes are required in device-sdk of edgex foundry. Files i checked (/internal/provision/devices.go) of device sdk if edgexfoundry. This is called at device startup.

Thanks for your effort!
Let me explain in more detail, edgex-metadata should send a request(the guide is incorrect) to the service for updating cache. However edgex-metadata doesn't do that.
When I called that REST API to datastorage, cache was updated.

edgex-metadata data

curl http://localhost:48081/api/v1/device
[{"created":1629351516733,"modified":1629351516733,"origin":1629351516731,"description":"RESTful Device","id":"774deba4-5469-4c38-8c2a-93a0f3c08252","name":"edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2",

CURL Request

$ curl -X 'POST' 'http://localhost:49986/api/v1/callback' -H 'accept: /' -H 'Content-Type: application/json' -d '{"type":"DEVICE","id":"774deba4-5469-4c38-8c2a-93a0f3c08252"}'

Edge Orchestration Log

INFO[2021-08-19T06:01:36Z]discovery.go:577 func1
level=INFO ts=2021-08-19T06:02:25.506828567Z app=datastorage source=device.go:72 msg="Added device: edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2"
INFO[2021-08-19T06:02:25Z]storagedriver.go:73 AddDevice [storagedriver] Device has been successfully added!!!!!! edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2
level=DEBUG ts=2021-08-19T06:02:25.50692288Z app=datastorage source=device.go:82 msg="Invoked driver.AddDevice callback for edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2"
level=DEBUG ts=2021-08-19T06:02:25.50693632Z app=datastorage source=device.go:89 msg="Handler - starting AutoEvents for device edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2"

I think edgex would be fixed or we can add some workaround code to datastorage.
What do you prefer? (Sharing this issue to edgex is good for open source collaboration

[nitu-s-gupta]

@t25kim How about raising an issue in edgex github of device sdk?, so that it can be updated. Workaround can be done like calling the API. But one more thing I noticed is storagedriver we have callbacks, those should be invoked when the device is added. But that too is not invoked, since the work aorund steps would be included there

[MoonkiHong]

This issue is from EdgeX side, Whenevr the service is started the devices already present in metadata are loaded in cache. But the devices which are added are not addded to cache. Hence this doesnot occur after reboot. I have tried with device-rest.go. Observed the same behaviour. Changes are required in device-sdk of edgex foundry. Files i checked (/internal/provision/devices.go) of device sdk if edgexfoundry. This is called at device startup.

Thanks for your effort!
Let me explain in more detail, edgex-metadata should send a request(the guide is incorrect) to the service for updating cache. However edgex-metadata doesn't do that.
When I called that REST API to datastorage, cache was updated.

edgex-metadata data

curl http://localhost:48081/api/v1/device
[{"created":1629351516733,"modified":1629351516733,"origin":1629351516731,"description":"RESTful Device","id":"774deba4-5469-4c38-8c2a-93a0f3c08252","name":"edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2",

CURL Request

$ curl -X 'POST' 'http://localhost:49986/api/v1/callback' -H 'accept: /' -H 'Content-Type: application/json' -d '{"type":"DEVICE","id":"774deba4-5469-4c38-8c2a-93a0f3c08252"}'

Edge Orchestration Log

INFO[2021-08-19T06:01:36Z]discovery.go:577 func1
level=INFO ts=2021-08-19T06:02:25.506828567Z app=datastorage source=device.go:72 msg="Added device: edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2"
INFO[2021-08-19T06:02:25Z]storagedriver.go:73 AddDevice [storagedriver] Device has been successfully added!!!!!! edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2
level=DEBUG ts=2021-08-19T06:02:25.50692288Z app=datastorage source=device.go:82 msg="Invoked driver.AddDevice callback for edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2"
level=DEBUG ts=2021-08-19T06:02:25.50693632Z app=datastorage source=device.go:89 msg="Handler - starting AutoEvents for device edge-orchestration-c1b23cc6-0767-400a-9cf0-36e1b3902da2"

I think edgex would be fixed or we can add some workaround code to datastorage.
What do you prefer? (Sharing this issue to edgex is good for open source collaboration

@jpwhitemn Hi, we encouter the issue w.r.t. the data storage that has been related to EdgeX Foundry. Could you introduce us the right person from the EdgeX community to discuss and/or to resolve this topic? 😄

[tiokim]

How about raising an issue in edgex github of device sdk?, so that it can be updated. Workaround can be done like calling the API. But one more thing I noticed is storagedriver we have callbacks, those should be invoked when the device is added. But that too is not invoked, since the work aorund steps would be included there

I agree to share this issue with edgex. However if the patch isn't implemented on edgex before home edge d-release, let's fix it on Edge Orchestration.

[nitu-s-gupta]

.search-word { BACKGROUND-COLOR: #ffee94 } P { FONT-SIZE: 10pt; MARGIN-BOTTOM: 5px; FONT-FAMILY: Arial, arial; MARGIN-TOP: 5px } TD { FONT-SIZE: 10pt; MARGIN-BOTTOM: 5px; FONT-FAMILY: Arial, arial; MARGIN-TOP: 5px } LI { FONT-SIZE: 10pt; MARGIN-BOTTOM: 5px; FONT-FAMILY: Arial, arial; MARGIN-TOP: 5px } BODY { FONT-SIZE: 10pt; FONT-FAMILY: Arial, arial } P { FONT-SIZE: 10pt; MARGIN-BOTTOM: 5px; FONT-FAMILY: Arial, arial; MARGIN-TOP: 5px }   Hello Peter,   The issue is not from the EdgeX side. After discussing with Cloud Tsai I understood its the usage of wrong IP address because of which the coredata was not able to invoke the callback and hence the cache not update. For local machine, the issue is resolved by using docker0 IP address as I tested it. But now the issue is the scenario that Taewan has very well mentioned EdgeX running independently on one device and Edge-Orchestration running on another device connected in network. So this has to be tested irrespective of the cache issue. I m trying to do that similar setup. Though I tested the similar scenario with normal pinging docker (alpine) and was able to setup communication using overlay network. Now I need to try out for the edge-orchestration.   Thanks & Regards Nitu   --------- Original Message --------- Sender : Peter Moonki ***@***.***> Date : 2021-09-07 07:46 (GMT+5:30) Title : Re: [lf-edge/edge-home-orchestration-go] [DataStorage] can not find device in cache (#312) To : ***@***.***> CC : Nitu Sajjanlal ***@***.***>, ***@***.***>   @nitu-s-gupta What do you think of resolving this issue from HomeEdge instead of requesting it at EdgeX, since it seems to me that the rationale of our request conflicts to the existing device-sdk-go at EdgeX? —You are receiving this because you were mentioned.Reply to this email directly, view it on GitHub, or unsubscribe.Triage notifications on the go with GitHub Mobile for iOS or Android.

[MoonkiHong]

Thank you for your kind clarification, @nitu-s-gupta 😄