SDK doesn't populate Device cache on first run of device service

[lenny-goodell]

Using latest SDK from master (v0.0.0-20191015162939-14f308f7b3dc as of 10/16/2019) the SDK no longer populates the Device cache for new devices, i.e. when the device service first runs.

The Device cache is then populated properly when the device service is restarted.

Reproduce this issue by:

• Updating device-virtual-go to latest SDK
• Build and run with fresh DB.
• Try sending GET to http://localhost:49995/api/v1/device/name/Random-Float-Device/RandomValue_Float32.
  -This will result in error stating Random-Float-Device not found

Restart the service and resend the GET results in expected result of RandomValue_Float32 being generated.

Note the Profile cache is probably not populated either.

[cloudxxx8]

I've verified it works fine with device-simple, and I am looking into device-virtual

[cloudxxx8]

it also works fine in device-modbus, moving this issue to device-virtual

[cloudxxx8]

new issue opened in device-virtual-go
edgexfoundry/device-virtual-go#56

[lenny-goodell]

@cloudxxx8, I discovered this with my new device-rest-go and confirmed it in device-virtual-go. I did't see this issue until updating to the latest version of the SDK.

[cloudxxx8]

@lenny-intel ok, I will take more time on this by Monday. We have to fix issue before release.

[lenny-goodell]

@cloudxxx8 , I just confirmed this issue also with device-random. After a clean start (i.e. no device,profile, etc in DB) I get following error when submitting GET to http://localhost:49988/api/v1/device/name/Random-Integer-Generator01/RandomValue_Int8

Device: Random-Integer-Generator01 not found; GET /api/v1/device/name/Random-Integer-Generator01/RandomValue_Int8

Once I restarted device-random the GET works as expected.

Interestingly, autoevents are working fine.

Note that I debugged this issue with the REST DS and found that the Device cache, and likely the Profile cache are no longer being populate on the first run of the service.

[jdharms]

@lenny-intel I think I'm running into a similar issue with some testing I'm doing today using device-virtual.

When I run device-virtual for the first time, GET commands work just fine, but PUT commands (with proper json payload) return 400's with this payload:

Handler - execWriteCmd: Put parameters parsing failed: {
	"Min_Int8": "40",
    "Max_Int8": "50"
} /api/v1/device/394fc244-d694-415b-9033-38537deb559c/GenerateRandomValue_Int8

Some logging from the device:

level=ERROR ts=2019-10-18T21:34:39.778534Z app=device-random source=command.go:306 msg="the parameter  does not match any DeviceResource in DeviceProfile"
level=ERROR ts=2019-10-18T21:34:39.778589Z app=device-random source=command.go:307 msg="Handler - execWriteCmd: Put parameters parsing failed: {\n\t\"Min_Int8\": \"40\",\n    \"Max_Int8\": \"50\"\n}"

When I restart the device-random ds, the PUT command works just fine again.

Clearing the database allows me to repro.

[cloudxxx8]

This issue will be resolve after merging #379 and #381

[cloudxxx8]

still needs #381

[cloudxxx8]

fixed by #381

[lenny-goodell]

@cloudxxx8 , I just tested this fix using latest on master for the SDK and still have the same issue. go.mod file is using github.com/edgexfoundry/device-sdk-go v0.0.0-20191022125515-529816d7109b

529816d7109b is the commit for merging #381

[cloudxxx8]

Do you encounter this issue in both REST and Virtual?

[cloudxxx8]

there is another issue needs to be fixed in virtual
edgexfoundry/device-virtual-go#59

[lenny-goodell]

@cloudxxx8 , still see the issue in REST and Random.

[lenny-goodell]

@cloudxxx8 , I comment on the latest for PR this about new issue created by that change.

Also seeing this error message on first run (REST and Random) and still seeing the device not found issue with the latest changes.
level=ERROR ts=2019-10-23T16:12:28.093937Z app=device-random source=profiles.go:197 msg="Error when retrieving EnableValueDescriptorManagement configuration from Core Metadata: map[LogLevel:INFO]"

Error message from device-random on first clean run:
Device: Random-Integer-Generator01 not found; GET /api/v1/device/name/Random-Integer-Generator01/RandomValue_Int8

Seeing same on REST DS.

Looks like profiles are getting cached, but not devices. I will debug some more today.

[cloudxxx8]

sorry, I am not sure the reason. We made the verification on virtual, simple, and random.
We will keep fixing this tomorrow.
Add @FelixTing and @weichou1229

[lenny-goodell]

@cloudxxx8 , @FelixTing , @weichou1229 , I have traced this change:

42d494f#diff-f1021e656b92dfcfce91344acd0292bcL71

Adding this line back fixes my issue. I will create a PR later today.

[lenny-goodell]

This ended up being issue with Core MetaData callback not working correctly because the mixed local (DS) and docker (core service) environment that I was testing in. Once I ran core service locally (make run), the callback worked and devices were added on first run.