GET/PUT command with MQTT-test-device does not work, 500 response reported

[M0hanrajp]

Please note this discussion is created to address MQTT-test-device issue.

[Issue]:

GET/PUT command with MQTT-test-device does not work with any of the test devices:

randfloat32:

 curl http://localhost:59882/api/v3/device/name/MQTT-test-device/randfloat32 | json_pp

{
   "apiVersion" : "v3",
   "message" : "request failed, status code: 500, err: {\"apiVersion\":\"v3\",\"message\":\"error reading Regex DeviceResource(s) randfloat32 for MQTT-test-device -\\u003e can not fetch command response: method=get source=randfloat32\",\"statusCode\":500}",
   "statusCode" : 500
}

randfloat64:

 curl http://localhost:59882/api/v3/device/name/MQTT-test-device/randfloat64 | json_pp

{
   "apiVersion" : "v3",
   "message" : "request failed, status code: 500, err: {\"apiVersion\":\"v3\",\"message\":\"error reading Regex DeviceResource(s) randfloat64 for MQTT-test-device -\\u003e can not fetch command response: method=get source=randfloat64\",\"statusCode\":500}",
   "statusCode" : 500
}

ping:

curl http://localhost:59882/api/v3/device/name/MQTT-test-device/ping | json_pp

{
   "apiVersion" : "v3",
   "message" : "request failed, status code: 500, err: {\"apiVersion\":\"v3\",\"message\":\"error reading Regex DeviceResource(s) ping for MQTT-test-device -\\u003e can not fetch command response: method=get source=ping\",\"statusCode\":500}",
   "statusCode" : 500
}

message:

curl http://localhost:59882/api/v3/device/name/MQTT-test-device/message | json_pp

{
   "apiVersion" : "v3",
   "message" : "request failed, status code: 500, err: {\"apiVersion\":\"v3\",\"message\":\"error reading Regex DeviceResource(s) message for MQTT-test-device -\\u003e can not fetch command response: method=get source=message\",\"statusCode\":500}",
   "statusCode" : 500
}

json:

curl http://localhost:59882/api/v3/device/name/MQTT-test-device/json | json_pp

{
   "apiVersion" : "v3",
   "message" : "request failed, status code: 500, err: {\"apiVersion\":\"v3\",\"message\":\"error reading Regex DeviceResource(s) json for MQTT-test-device -\\u003e can not fetch command response: method=get source=json\",\"statusCode\":500}",
   "statusCode" : 500
}

allValues:

curl http://localhost:59882/api/v3/device/name/MQTT-test-device/allValues | json_pp

{
   "apiVersion" : "v3",
   "message" : "request failed, status code: 500, err: {\"apiVersion\":\"v3\",\"message\":\"error reading DeviceCommand allValues for MQTT-test-device -\\u003e can not fetch command response: method=get source=randfloat32\",\"statusCode\":500}",
   "statusCode" : 500
}

---

Device-mqtt side logs:

edgex-device-mqtt  | level=DEBUG source=driver.go:137 msg="Publish command: "
edgex-device-mqtt  | level=ERROR source=driver.go:111 msg="Handle read commands failed: can not fetch command response: method=get source=randfloat32"
edgex-device-mqtt  | level=ERROR source=restrouter.go:159 X-Correlation-ID=2f181443-66e9-40b1-9405-70bc48632e9c msg="error reading Regex DeviceResource(s) randfloat32 for MQTT-test-device -> can not fetch command response: method=get source=randfloat32"
edgex-device-mqtt  | level=DEBUG source=restrouter.go:160 X-Correlation-ID=2f181443-66e9-40b1-9405-70bc48632e9c msg="[github.com/edgexfoundry/device-sdk-go/[email protected]/internal/application/command.go]-github.com/edgexfoundry/device-sdk-go/v3/internal/application.GetCommand(line 61):  -> [github.com/edgexfoundry/device-sdk-go/[email protected]/internal/application/command.go]-github.com/edgexfoundry/device-sdk-go/v3/internal/application.readDeviceResourcesRegex(line 194): error reading Regex DeviceResource(s) randfloat32 for MQTT-test-device -> [github.com/edgexfoundry/device-mqtt-go/internal/driver/driver.go]-github.com/edgexfoundry/device-mqtt-go/internal/driver.(*Driver).handleReadCommandRequest(line 142): can not fetch command response: method=get source=randfloat32"
...
...
edgex-device-mqtt  | level=DEBUG source=driver.go:137 msg="Publish command: "
edgex-device-mqtt  | level=DEBUG source=reporter.go:195 msg="Publish 0 metrics to the 'edgex/telemetry/device-mqtt' base topic"
edgex-device-mqtt  | level=DEBUG source=manager.go:123 msg="Reported metrics..."
edgex-device-mqtt  | level=ERROR source=driver.go:111 msg="Handle read commands failed: can not fetch command response: method=get source=randfloat64"
edgex-device-mqtt  | level=ERROR source=restrouter.go:159 X-Correlation-ID=bb54c944-6665-4a55-ae64-7c1ae114c8e6 msg="error reading Regex DeviceResource(s) randfloat64 for MQTT-test-device -> can not fetch command response: method=get source=randfloat64"
edgex-device-mqtt  | level=DEBUG source=restrouter.go:160 X-Correlation-ID=bb54c944-6665-4a55-ae64-7c1ae114c8e6 msg="[github.com/edgexfoundry/device-sdk-go/[email protected]/internal/application/command.go]-github.com/edgexfoundry/device-sdk-go/v3/internal/application.GetCommand(line 61):  -> [github.com/edgexfoundry/device-sdk-go/[email protected]/internal/application/command.go]-github.com/edgexfoundry/device-sdk-go/v3/internal/application.readDeviceResourcesRegex(line 194): error reading Regex DeviceResource(s) randfloat64 for MQTT-test-device -> [github.com/edgexfoundry/device-mqtt-go/internal/driver/driver.go]-github.com/edgexfoundry/device-mqtt-go/internal/driver.(*Driver).handleReadCommandRequest(line 142): can not fetch command response: method=get source=randfloat64"
...
...
edgex-device-mqtt  | level=DEBUG source=driver.go:137 msg="Publish command: "
edgex-device-mqtt  | level=ERROR source=driver.go:111 msg="Handle read commands failed: can not fetch command response: method=get source=message"
edgex-device-mqtt  | level=ERROR source=restrouter.go:159 X-Correlation-ID=ff7d82e9-7767-4a5f-a023-94e1328d81b3 msg="error reading Regex DeviceResource(s) message for MQTT-test-device -> can not fetch command response: method=get source=message"
edgex-device-mqtt  | level=DEBUG source=restrouter.go:160 X-Correlation-ID=ff7d82e9-7767-4a5f-a023-94e1328d81b3 msg="[github.com/edgexfoundry/device-sdk-go/[email protected]/internal/application/command.go]-github.com/edgexfoundry/device-sdk-go/v3/internal/application.GetCommand(line 61):  -> [github.com/edgexfoundry/device-sdk-go/[email protected]/internal/application/command.go]-github.com/edgexfoundry/device-sdk-go/v3/internal/application.readDeviceResourcesRegex(line 194): error reading Regex DeviceResource(s) message for MQTT-test-device -> [github.com/edgexfoundry/device-mqtt-go/internal/driver/driver.go]-github.com/edgexfoundry/device-mqtt-go/internal/driver.(*Driver).handleReadCommandRequest(line 142): can not fetch command response: method=get source=message"
...
...
edgex-device-mqtt  | level=DEBUG source=driver.go:137 msg="Publish command: "
edgex-device-mqtt  | level=ERROR source=driver.go:111 msg="Handle read commands failed: can not fetch command response: method=get source=json"
edgex-device-mqtt  | level=ERROR source=restrouter.go:159 X-Correlation-ID=45c8b828-d597-4ec2-9c7b-e8b7698938fc msg="error reading Regex DeviceResource(s) json for MQTT-test-device -> can not fetch command response: method=get source=json"
edgex-device-mqtt  | level=DEBUG source=restrouter.go:160 X-Correlation-ID=45c8b828-d597-4ec2-9c7b-e8b7698938fc msg="[github.com/edgexfoundry/device-sdk-go/[email protected]/internal/application/command.go]-github.com/edgexfoundry/device-sdk-go/v3/internal/application.GetCommand(line 61):  -> [github.com/edgexfoundry/device-sdk-go/[email protected]/internal/application/command.go]-github.com/edgexfoundry/device-sdk-go/v3/internal/application.readDeviceResourcesRegex(line 194): error reading Regex DeviceResource(s) json for MQTT-test-device -> [github.com/edgexfoundry/device-mqtt-go/internal/driver/driver.go]-github.com/edgexfoundry/device-mqtt-go/internal/driver.(*Driver).handleReadCommandRequest(line 142): can not fetch command response: method=get source=json"
...
...
# similar error observed further.

[somashekhar-bm]

Steps to set up and simulate an MQTT device using EdgeX Foundry:

1. Generate the docker-compose.yml file (this includes mqtt-broker):

   $ cd compose-builder
   $ make gen ds-mqtt mqtt-broker mqtt-verbose no-secty ui
   $ sudo docker compose up -d

2. Create a Device Profile in EdgeX UI:

   • Name: "my-custom-device-profile"
   • Manufacturer: "iot"
   • Model: "MQTT-DEVICE"
   • Description: "Test device profile"
   • Labels:
     • "mqtt"
     • "test"
   • Device Resources:

     deviceResources:
       - name: randnum
         isHidden: true
         description: "device random number"
         properties:
           valueType: "Float32"
           readWrite: "R"
       - name: ping
         isHidden: true
         description: "device awake"
         properties:
           valueType: "String"
           readWrite: "R"
       - name: message
         isHidden: false
         description: "device message"
         properties:
           valueType: "String"
           readWrite: "RW"
       - name: json
         isHidden: false
         description: "JSON message"
         properties:
           valueType: "Object"
           readWrite: "RW"
           mediaType: "application/json"

   • Device Commands:

     deviceCommands:
       - name: values
         readWrite: "R"
         isHidden: false
         resourceOperations:
           - { deviceResource: "randnum" }
           - { deviceResource: "ping" }
           - { deviceResource: "message" }

3. Create an MQTT Device in EdgeX UI:

   deviceList:
     - name: "my-custom-device"
       profileName: "my-custom-device-profile"
       description: "MQTT device created for test purpose"
       labels: [ "MQTT", "test" ]
       protocols:
         mqtt:
           CommandTopic: "command/my-custom-device"
       autoEvents:
         - interval: "30s"
           onChange: false
           sourceName: "message"

4. Create and Run an MQTT Device Simulator:

   • Create a JavaScript file named mock-device.js with the following content:

     function getRandomFloat(min, max) {
         return Math.random() * (max - min) + min;
     }
     
     const deviceName = "my-custom-device";
     let message = "test-message";
     let json = {"name" : "My JSON"};
     
     // DataSender sends async value to MQTT broker every 15 seconds
     schedule('*/15 * * * * *', ()=>{
         var data = {};
         data.randnum = getRandomFloat(25,29).toFixed(1);
         data.ping = "pong";
         data.message = "Hello World";
     
         publish('incoming/data/my-custom-device/values', JSON.stringify(data));
     });
     
     // CommandHandler receives commands and sends response to MQTT broker
     subscribe("command/my-custom-device/#", (topic, val) => {
         const words = topic.split('/');
         var cmd = words[2];
         var method = words[3];
         var uuid = words[4];
         var response = {};
         var data = val;
     
         if (method == "set") {
             switch(cmd) {
                 case "message":
                     message = data[cmd];
                     break;
                 case "json":
                     json = data[cmd];
                     break;
             }
         } else {
             switch(cmd) {
                 case "ping":
                     response.ping = "pong";
                     break;
                 case "message":
                     response.message = message;
                     break;
                 case "randnum":
                     response.randnum = 12.123;
                     break;
                 case "json":
                     response.json = json;
                     break;
             }
         }
         var sendTopic = "command/response/" + uuid;
         publish(sendTopic, JSON.stringify(response));
     });

   • Create a directory mqtt-scripts and move mock-device.js to it:

     $ mv mock-device.js /path/to/mqtt-scripts

   • Run the following command to start the simulator:

     $ docker run --rm --name=mqtt-scripts -v /path/to/mqtt-scripts:/scripts --network host -e LOG_LEVEL=DEBUG dersimn/mqtt-scripts --dir /scripts --verbose

   • The MQTT scripts will show logs like:

     2022-08-12 09:52:42.086 <info>  mqtt-scripts 1.2.2 starting
     2022-08-12 09:52:42.227 <info>  mqtt connected mqtt://127.0.0.1
     2022-08-12 09:52:42.733 <info>  /scripts/mock-device.js loading
     

[M0hanrajp]

Thanks @somashekhar-bm , It works !

edgex-device-mqtt  | level=INFO ts=2024-09-05T11:03:05.761672593Z app=device-mqtt source=messaging.go:104 msg="Connected to redis Message Bus @ redis://edgex-redis:6379 with AuthMode='usernamepassword'"
edgex-device-mqtt  | level=INFO ts=2024-09-05T11:03:05.821406701Z app=device-mqtt source=driver.go:457 msg="Subscribed to topic 'incoming/data/#' for receiving the async reading"
edgex-device-mqtt  | level=INFO ts=2024-09-05T11:03:05.822109067Z app=device-mqtt source=driver.go:466 msg="Subscribed to topic 'command/response/#' for receiving the request response"
edgex-device-mqtt  | level=INFO ts=2024-09-05T11:03:05.855118047Z app=device-mqtt source=message.go:51 msg="Starting device-mqtt 3.1.1 "
edgex-device-mqtt  | level=INFO ts=2024-09-05T11:03:05.85549251Z app=device-mqtt source=message.go:55 msg="device mqtt started"
edgex-device-mqtt  | level=INFO ts=2024-09-05T11:03:05.855564903Z app=device-mqtt source=message.go:58 msg="Service started in: 11.769017736s"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:00.013502995Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: randnum reading: {Id:d9508d0d-f296-48f3-94fc-48b04f658d1a Origin:1725534660011275182 DeviceName:my-custom-device ResourceName:randnum ProfileName:my-custom-device-profile ValueType:Float32 Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:2.810000e+01} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:00.013886519Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: ping reading: {Id:a42df9be-4c8d-4698-8612-af5340061c48 Origin:1725534660011291588 DeviceName:my-custom-device ResourceName:ping ProfileName:my-custom-device-profile ValueType:String Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:pong} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:00.014089166Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: message reading: {Id:b55561da-d7b3-4a3a-b98a-a6433823d6f0 Origin:1725534660011366949 DeviceName:my-custom-device ResourceName:message ProfileName:my-custom-device-profile ValueType:String Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:Hello World} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:00.016382185Z app=device-mqtt source=utils.go:82 msg="Event(profileName: my-custom-device-profile, deviceName: my-custom-device, sourceName: values, id: 6f8c2351-1ccd-43f2-9f76-f986850ed50b) published to MessageBus on topic: edgex/events/device/device-mqtt/my-custom-device-profile/my-custom-device/values"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:05.008352277Z app=device-mqtt source=incominglistener.go:108 msg="[Incoming listener] Incoming reading received: topic=incoming/data/my-custom-device/values msg={\"randnum\":\"27.5\",\"ping\":\"pong\",\"message\":\"Hello World\"}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:05.009044173Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: randnum reading: {Id:c306c77f-ab88-4f40-b025-eb81386b4568 Origin:1725534665008280614 DeviceName:my-custom-device ResourceName:randnum ProfileName:my-custom-device-profile ValueType:Float32 Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:2.750000e+01} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:05.009256299Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: ping reading: {Id:46f6091c-537a-4728-acd3-2c7e8847dbd3 Origin:1725534665008296082 DeviceName:my-custom-device ResourceName:ping ProfileName:my-custom-device-profile ValueType:String Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:pong} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:05.009448425Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: message reading: {Id:7f071be3-686d-44f8-8bc1-957d62fb3245 Origin:1725534665008303790 DeviceName:my-custom-device ResourceName:message ProfileName:my-custom-device-profile ValueType:String Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:Hello World} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:05.012960245Z app=device-mqtt source=utils.go:82 msg="Event(profileName: my-custom-device-profile, deviceName: my-custom-device, sourceName: values, id: 0f2213f7-bd5a-4b99-8b9d-573a6fc06393) published to MessageBus on topic: edgex/events/device/device-mqtt/my-custom-device-profile/my-custom-device/values"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:05.779577171Z app=device-mqtt source=reporter.go:195 msg="Publish 0 metrics to the 'edgex/telemetry/device-mqtt' base topic"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:05.779793307Z app=device-mqtt source=manager.go:123 msg="Reported metrics..."
edgex-device-mqtt  | level=TRACE ts=2024-09-05T11:11:07.155235804Z app=device-mqtt source=common_middleware.go:51 X-Correlation-ID=8e6aee92-aa6f-40ab-b4b1-78212ac31a6e path=/api/v3/ping msg="Begin request"
edgex-device-mqtt  | level=TRACE ts=2024-09-05T11:11:07.162900563Z app=device-mqtt source=common_middleware.go:57 X-Correlation-ID=8e6aee92-aa6f-40ab-b4b1-78212ac31a6e duration=7.676372ms msg="Response complete"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:10.008222312Z app=device-mqtt source=incominglistener.go:108 msg="[Incoming listener] Incoming reading received: topic=incoming/data/my-custom-device/values msg={\"randnum\":\"28.5\",\"ping\":\"pong\",\"message\":\"Hello World\"}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:10.008939675Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: randnum reading: {Id:30d7ca56-4283-4923-92c8-c5b676d848e2 Origin:1725534670008138826 DeviceName:my-custom-device ResourceName:randnum ProfileName:my-custom-device-profile ValueType:Float32 Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:2.850000e+01} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:10.009221902Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: ping reading: {Id:b9461c13-46e1-49d5-a0e9-86ba2aac639b Origin:1725534670008152888 DeviceName:my-custom-device ResourceName:ping ProfileName:my-custom-device-profile ValueType:String Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:pong} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:10.009455486Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: message reading: {Id:67784dc9-4360-4052-98fc-33afe1c21228 Origin:1725534670008160700 DeviceName:my-custom-device ResourceName:message ProfileName:my-custom-device-profile ValueType:String Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:Hello World} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:10.0114317Z app=device-mqtt source=utils.go:82 msg="Event(profileName: my-custom-device-profile, deviceName: my-custom-device, sourceName: values, id: 4b73a2c0-620a-455c-b054-8619dd20deb0) published to MessageBus on topic: edgex/events/device/device-mqtt/my-custom-device-profile/my-custom-device/values"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:15.00814007Z app=device-mqtt source=incominglistener.go:108 msg="[Incoming listener] Incoming reading received: topic=incoming/data/my-custom-device/values msg={\"randnum\":\"26.5\",\"ping\":\"pong\",\"message\":\"Hello World\"}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:15.008889829Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: randnum reading: {Id:2ab6352a-1beb-4396-b054-ff4a2bccde05 Origin:1725534675008058146 DeviceName:my-custom-device ResourceName:randnum ProfileName:my-custom-device-profile ValueType:Float32 Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:2.650000e+01} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:15.009119767Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: ping reading: {Id:c5eff133-439d-4f98-badc-6fcd500a260a Origin:1725534675008072521 DeviceName:my-custom-device ResourceName:ping ProfileName:my-custom-device-profile ValueType:String Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:pong} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:15.009313508Z app=device-mqtt source=transform.go:123 msg="device: my-custom-device DeviceResource: message reading: {Id:f8f263df-60c7-4dd1-9a7f-4888e902d366 Origin:1725534675008080177 DeviceName:my-custom-device ResourceName:message ProfileName:my-custom-device-profile ValueType:String Units: Tags:map[] BinaryReading:{BinaryValue:[] MediaType:} SimpleReading:{Value:Hello World} ObjectReading:{ObjectValue:<nil>}}"
edgex-device-mqtt  | level=DEBUG ts=2024-09-05T11:11:15.013159798Z app=device-mqtt source=utils.go:82 msg="Event(profileName: my-custom-device-profile, deviceName: my-custom-device, sourceName: values, id: 21b1c63d-7def-4ebd-b368-b08a65a87ef1) published to MessageBus on topic: edgex/events/device/device-mqtt/my-custom-device-profile/my-custom-device/values"