Listen and wait pattern for mqtt causes performance issue

[qs-wang]

🚀 Feature Request

Relevant Package： internal/pkg/request.go and core-command

This feature request is for changing the send and wait implementation for mqtt

Description

At this time in the DoRequest function of internal/pkg/request.go, it implements with a send and wait(with timeout) pattern.

If user sends the command quickly, for example I tried to send read command to core command with 1s delay, the core command will reports timeout quickly.

The error is as following:
level=ERROR ts=2025-07-07T23:42:51.342820133Z app=core-command source=internal.go:166 msg="Request to topic 'edgex/device/command/request/servicename/devicename/SwitchStatus/get' failed: timed out waiting for response on edgex/response/servicename/fc9f200c-044a-48de-a3b6-357c4b992ff0 topic"
level=ERROR ts=2025-07-07T23:44:21.358288411Z app=core-command source=internal.go:166 msg="Request to topic 'edgex/device/command/request/servicename/devicename/SwitchStatus/get' failed: unable to create response subscription: Timeout occured while performing a 'Subscribe' operation: Failed to create subscription".
I have tested with a dummy device service. The result shows that the issue is from this send and wait pattern, not from a slow device service.

I think this is not idea for a sub/pub solution.

Describe the solution you'd like

For an event driven case I'd suggest to have following solution

1. Remove the sub and wait
2. redesign the topic. At this time the response topic is as following
   edgex/response/servicename which is not easy to distinguish from other topic for example edgex/response/core-command.
   I'd propose something as edgex/response/devices/xxxx
3. Have a global sub which is listening on edgex/response/devices/#. Then this sub forward the messages to edgex/response/core-command which makes it be compatible with current behavior.

Please let me know the feedback. I'd be happy to contribute a PR for this.

[lindseysimple]

@qs-wang Based on the log message you shared, it appears that the request and response topic values are incorrect. The placeholders servicename and devicename in the request topic edgex/device/command/request/servicename/devicename/SwitchStatus/get should be replaced with actual values — for example:
edgex/device/command/request/device-simple/Simple-Device01/SwitchStatus/get.

Similarly, the expected response topic should follow the format:
edgex/response/core-command/fc9f200c-044a-48de-a3b6-357c4b992ff0.

Could you share the part of your code where you initialize the command client and invoke the DoRequest method? This will help us better understand the issue, thanks!

[idiazcir]

We are experiencing the same error. With the upgrade from EdgeX 3.1 to 4.0 and now using MQTT, there seems to have been a change that makes using the CommandClient() "quickly" break it.
(NOTE: We managed to generate the same error on the 3.1 version, but the number of "concurrent/quick" calls that must be made to generate the error is much higher)

In our case, we use the CommandClient() via the SDK from an application on the north. Example:

func issueGetCommand(client clients.CommandClient) error {
	_, err := client.IssueGetCommandByName(context.Background(), "Random-Boolean-Device", "Bool", false, false)
	return err
}

If this function is called more than once without a substantial delay between calls, it fails, and makes the subsequent calls fail as well.

We have been able to reproduce this behavior using a dummy application that utilizes the device-virtual

• Deploy: edgex-compose with on tag v4.0 command docker compose -f docker-compose-no-secty.yml up -d (with the dummy application added as another service on the deploy file.
• Application code (main.go):

package main

import (
	"context"
	"fmt"
	"time"

	"app-new-service/config"

	"github.com/edgexfoundry/app-functions-sdk-go/v4/pkg"
	"github.com/edgexfoundry/app-functions-sdk-go/v4/pkg/interfaces"
	clients "github.com/edgexfoundry/go-mod-core-contracts/v4/clients/interfaces"
	"github.com/edgexfoundry/go-mod-core-contracts/v4/clients/logger"
)

const (
	serviceKey = "app-new-service"
)

type myApp struct {
	service       interfaces.ApplicationService
	lc            logger.LoggingClient
	appCtx        context.Context
	serviceConfig *config.ServiceConfig
	configChanged chan bool
}

func main() {
	sdk, ok := pkg.NewAppService(serviceKey)
	if !ok {
		fmt.Printf("Failed to create service factory for %s\n", serviceKey)
		return
	}
	client := sdk.CommandClient()
	if client == nil {
		fmt.Printf("Failed to create command client for %s\n", serviceKey)
		return
	}

	// 1. Issue a Get command each 1 second
	go func() {
		for {
			err := issueGetCommand(client)
			if err != nil {
				fmt.Printf("[Periodic] - FAILED: %v\n", err)
			} else {
				fmt.Printf("[Periodic] - SUCCESS\n")
			}

			// Sleep for 1 second before issuing the next command
			time.Sleep(1 * time.Second)
		}
	}()

	// 2. Wait 10 seconds, see the periodic one works.
	time.Sleep(10 * time.Second)

	// 3. Ask repeatedly 10 time
	for i := 0; i < 10; i++ {
		go func() {
			err := issueGetCommand(client)
			if err != nil {
				fmt.Printf("[Request] - FAILED: %v\n", err)
			} else {
				fmt.Printf("[Request] - SUCCESS\n")
			}
		}()
	}

	// 4. Wait a minute to see the periodic one works.
	time.Sleep(1 * time.Minute)
}

func issueGetCommand(client clients.CommandClient) error {
	_, err := client.IssueGetCommandByName(context.Background(), "Random-Boolean-Device", "Bool", false, false)
	return err
}

The code makes some periodic calls with a 1 sec delay between calls. Those work initially fine. After 10 sec we then send 10 commands concurrently without delay. Those fail directly. The rest of the subsequent periodic calls start failing too from that moment on. Which seems to leave the CommandClient unable to make calls. Even if the application is restarted, it fails. For it to work again, we need to stop EdgeX.

• Logs:

[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/77af54a1-3a4b-49d6-a92e-392935d69c35 topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/aeefb462-54e2-4aa4-97b9-8e1d48c52a64 topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/4752deb1-32ab-40a7-a51d-79a9f33161dd topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/8f475dc1-3caa-461d-83ec-8c0e3d3b024b topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/e422654a-1995-4549-8eab-2ed20e0e55df topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/b98ca241-7915-4ca7-aad7-f99f6b5316d4 topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/3fe5e58e-be5e-45e9-8d5a-dc9e05e2957b topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/1b8550d3-88cb-485d-b4ad-d1d0adb486e0 topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/96a31241-e25d-4f4e-ad18-d14f01926408 topic
[Request] - FAILED: timed out waiting for response on edgex/response/core-command/19a17408-3954-41a1-8a15-4cdb0584afb7 topic
[Periodic] - FAILED: timed out waiting for response on edgex/response/core-command/5e1d940d-ff9d-48b8-b08b-655d9b6abf8a topic
[Periodic] - FAILED: timed out waiting for response on edgex/response/core-command/957268e6-bb82-4b11-8153-93deb496802d topic

If you add a delay between the "quick calls" (in section // 3.) as follows:

	// 3. Ask repeatedly 10 time
	for i := 0; i < 10; i++ {
		err := issueGetCommand(client)
		if err != nil {
			fmt.Printf("[Request] - FAILED: %v\n", err)
		} else {
			fmt.Printf("[Request] - SUCCESS\n")
		}
		time.Sleep(500 * time.Millisecond) // Sleep for 500 milliseconds before the next request
	}

All the calls succeeded.

• Logs:

[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Request] - SUCCESS
[Periodic] - SUCCESS
[Request] - SUCCESS
[Request] - SUCCESS
[Periodic] - SUCCESS
[Request] - SUCCESS
[Request] - SUCCESS
[Periodic] - SUCCESS
[Request] - SUCCESS
[Request] - SUCCESS
[Periodic] - SUCCESS
[Request] - SUCCESS
[Request] - SUCCESS
[Periodic] - SUCCESS
[Request] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS
[Periodic] - SUCCESS

Hence, it seems the calls without a delay cause a timeout, which makes the command client unusable (needing to stop EdgeX).

For context, we have applications that need to send commands to devices to control them.

[idiazcir]

May this be related to this issue: #227 ?

[qs-wang]

May this be related to this issue: #227 ?

I don't think so. My team will try to provide a code package to reproduce this issue.

[rcortescir]

Update to @idiazcir 's comment:

We have also tested this dummy application with EdgeX v3.1.1, by iterating 1000 times the for loop (3.) without delay, and all commands seem to be sent successfully.

The strange thing is that even with v3.1 in our production code, where we send in a loop a series of Set command to a group of devices at the same time, with 5 seconds between each iteration, we are getting these timeout errors. Since the number of devices can vary in each scenario, we have tried different number of devices to see where it is breaking, with no clear indication about where the problem begins. This is what we saw:

• for 60 devices, on a given run, out of 100 commands that were sent, ~30 of them ended up in a timeout error
• also for 60 devices, on a later run, no timeouts were found in the tested time (~1000 commands)
• for 200 devices, the first iteration of commands (200 commands) are sent successfully, but after that all of the following commands end in a timeout error and the system never recovers to function normally

{"time":"2025-07-23T08:40:25.858088062Z","level":"ERROR","msg":"Failed to send limit fb19d3fc-f7cb-40a9-a137-68041fa75e55: timed out waiting for response on edgex/response/core-command/c78fa779-e438-4d24-b1fe-c4292f882242 topic","service":"app-x","source":{"file":"recalculation.go","line":102}}

Question: Could all of this be related to the resources (CPU, RAM) of the tested platform, therefore explaining why it fails sometimes and other it does not, with apparently the same conditions?

[qs-wang]

Update to @idiazcir 's comment:

We have also tested this dummy application with EdgeX v3.1.1, by iterating 1000 times the for loop (3.) without delay, and all commands seem to be sent successfully.

The strange thing is that even with v3.1 in our production code, where we send in a loop a series of Set command to a group of devices at the same time, with 5 seconds between each iteration, we are getting these timeout errors. Since the number of devices can vary in each scenario, we have tried different number of devices to see where it is breaking, with no clear indication about where the problem begins. This is what we saw:

* for 60 devices, on a given run, out of 100 commands that were sent, ~30 of them ended up in a timeout error

* also for 60 devices, on a later run, no timeouts were found in the tested time (~1000 commands)

* for 200 devices, the first iteration of commands (200 commands) are sent successfully, but after that all of the following commands end in a timeout error and the system never recovers to function normally

{"time":"2025-07-23T08:40:25.858088062Z","level":"ERROR","msg":"Failed to send limit fb19d3fc-f7cb-40a9-a137-68041fa75e55: timed out waiting for response on edgex/response/core-command/c78fa779-e438-4d24-b1fe-c4292f882242 topic","service":"app-x","source":{"file":"recalculation.go","line":102}}

Question: Could all of this be related to the resources (CPU, RAM) of the tested platform, therefore explaining why it fails sometimes and other it does not, with apparently the same conditions?

I cannot say for your case, but for my case we traced the load of the env and didn't see and peak at all. At this time my team temporarily patched the code which removed the wait piece, e.g. wait the response from edgex/response/core-command/fc9f200c-044a-48de-a3b6-357c4b992ff0, to make it work.

[idiazcir]

Can you share what part did you remove and where on your patch @qs-wang ? We would like to try it too

[qs-wang]

Can you share what part did you remove and where on your patch @qs-wang ? We would like to try it too

41ba467

the patch is simply remove the subscribe([]types.TopicChannel{responseTopicChan}, errs). We are subing to the service response channel directly for now.

[idiazcir]

We have just tried running EdgeX with NATS as the MessageBus instead of MQTT, and we are no longer encountering the error/timeout (at least with the test script above).

I assume the MQTT implementation is much more limiting in terms of resources and throughput, which is probably causing the timeout. I'm not sure why MQTT was chosen as the default message bus, but NATS seems like a better fit for the purpose.