edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.527529613Z app=device-mqtt source=variables.go:462 msg="Variables override of 'Startup Duration' by environment variable: EDGEX_STARTUP_DURATION=500"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.528399724Z app=device-mqtt source=config.go:718 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/core-common-config-bootstrapper/all-services"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.535045833Z app=device-mqtt source=config.go:442 msg="loading the common configuration for service type device-service"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.535160895Z app=device-mqtt source=config.go:718 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/core-common-config-bootstrapper/device-services"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.538744512Z app=device-mqtt source=config.go:173 msg="Common configuration loaded from the Configuration Provider. No overrides applied"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.538793938Z app=device-mqtt source=config.go:718 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/device-mqtt"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.544209114Z app=device-mqtt source=config.go:218 msg="Private configuration loaded from the Configuration Provider. No overrides applied"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.544271223Z app=device-mqtt source=config.go:269 msg="listening for private config changes"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.54428056Z app=device-mqtt source=config.go:271 msg="listening for all services common config changes"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.54428735Z app=device-mqtt source=config.go:278 msg="listening for device service common config changes"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.544304654Z app=device-mqtt source=registry.go:61 msg="Using Registry access token of length 0"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.544333744Z app=device-mqtt source=registry.go:89 msg="Using Registry (consul) from http://edgex-core-consul:8500"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.564784678Z app=device-mqtt source=httpserver.go:149 msg="Web server starting (edgex-device-mqtt:59982)"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.565740211Z app=device-mqtt source=messaging.go:104 msg="Connected to mqtt Message Bus @ tcp://edgex-mqtt-broker:1883 with AuthMode='none'"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.56578125Z app=device-mqtt source=command.go:36 msg="Subscribing to command requests on topic: edgex/device/command/request/device-mqtt/#"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.56578924Z app=device-mqtt source=command.go:40 msg="Responses to command requests will be published on topic: edgex/response/device-mqtt/<requestId>"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.567212701Z app=device-mqtt source=callback.go:34 msg="Subscribing to System Events on topic: edgex/system-events/core-metadata/+/+/device-mqtt/#"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.567570704Z app=device-mqtt source=validation.go:31 msg="Subscribing to device validation requests on topic: edgex/device-mqtt/validate/device"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.567601523Z app=device-mqtt source=validation.go:35 msg="Responses to device validation requests will be published on topic: edgex/response/device-mqtt/<requestId>"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.568079167Z app=device-mqtt source=manager.go:128 msg="Metrics Manager started with a report interval of 30s"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.568632525Z app=device-mqtt source=clients.go:190 msg="Using registry for URL for 'core-metadata': http://edgex-core-metadata:59881"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.568676741Z app=device-mqtt source=restrouter.go:56 msg="Registering v2 routes..."
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.573116415Z app=device-mqtt source=config.go:576 msg="Checking if custom configuration ('MQTTBrokerInfo') exists in Configuration Provider"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.574693972Z app=device-mqtt source=config.go:597 msg="Loaded custom configuration from Configuration Provider, no overrides applied"
edgex-device-mqtt  | level=DEBUG ts=2024-09-04T16:52:33.574734712Z app=device-mqtt source=driver.go:57 msg="Custom config is: &{{tcp edgex-mqtt-broker 1883 0 3600 device-mqtt 120 1 10 5 none credentials incoming/data/# command/response/# {500}}}"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.574758921Z app=device-mqtt source=config.go:690 msg="Watching for custom configuration changes has started for `MQTTBrokerInfo/Writable`"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.574768985Z app=device-mqtt source=driver.go:425 msg="Create MQTT client and connection: hostname=edgex-mqtt-broker clientID=device-mqtt "
edgex-device-mqtt  | level=DEBUG ts=2024-09-04T16:52:33.575596941Z app=device-mqtt source=service.go:281 msg="trying to find device service device-mqtt"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.575797591Z 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-04T16:52:33.576051196Z 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-04T16:52:33.576462752Z app=device-mqtt source=service.go:299 msg="device service device-mqtt exists, updating it"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.57726211Z 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-04T16:52:33.577493994Z 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-04T16:52:33.578583606Z app=device-mqtt source=profiles.go:89 msg="Loading pre-defined Device Profiles from /res/profiles(1 files found)"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.580676378Z app=device-mqtt source=profiles.go:190 msg="Device Profile Test-Device-MQTT-Profile exists, using the existing one"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.581151202Z app=device-mqtt source=devices.go:107 msg="Loading pre-defined Devices from /res/devices(1 files found)"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:33.581608566Z app=device-mqtt source=devices.go:189 msg="Device MQTT-test-device not found in Metadata, adding it ..."
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:35.583375571Z 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-04T16:52:35.58399593Z app=device-mqtt source=driver.go:466 msg="Subscribed to topic 'command/response/#' for receiving the request response"
edgex-device-mqtt  | level=TRACE ts=2024-09-04T16:52:36.88747356Z app=device-mqtt source=common_middleware.go:51 X-Correlation-ID=54f3c03b-1818-4069-b891-c1c25265610d path=/api/v3/ping msg="Begin request"
edgex-device-mqtt  | level=TRACE ts=2024-09-04T16:52:36.891440847Z app=device-mqtt source=common_middleware.go:57 X-Correlation-ID=54f3c03b-1818-4069-b891-c1c25265610d duration=3.968636ms msg="Response complete"
edgex-device-mqtt  | level=ERROR ts=2024-09-04T16:52:38.583635481Z app=device-mqtt source=init.go:104 msg="Failed to load devices: request failed, status code: 503, err: <html><head><title>Timeout</title></head><body><h1>Timeout</h1></body></html>"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583694042Z app=device-mqtt source=bootstrap.go:146 msg="Un-Registering service from the Registry"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583742198Z app=device-mqtt source=command.go:61 msg="Exiting waiting for MessageBus 'edgex/device/command/request/device-mqtt/#' topic messages"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583782592Z app=device-mqtt source=config.go:852 msg="Watching for 'Writable' configuration changes has stopped"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583799118Z app=device-mqtt source=config.go:852 msg="Watching for 'Writable' configuration changes has stopped"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.58378743Z app=device-mqtt source=validation.go:56 msg="Exiting waiting for MessageBus 'edgex/device-mqtt/validate/device' topic messages"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583817113Z app=device-mqtt source=callback.go:73 msg="Exiting waiting for MessageBus 'edgex/system-events/core-metadata/+/+/device-mqtt/#' topic messages"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583817785Z app=device-mqtt source=manager.go:110 msg="Exited Metrics Manager Run..."
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583830094Z app=device-mqtt source=config.go:790 msg="Watching for 'Writable' configuration changes has stopped"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583847453Z app=device-mqtt source=config.go:669 msg="Watching for 'MQTTBrokerInfo/Writable' configuration changes has stopped"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.583869903Z app=device-mqtt source=httpserver.go:174 msg="Web server stopped"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.584001149Z app=device-mqtt source=messaging.go:95 msg="Disconnected from MessageBus"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.584007889Z app=device-mqtt source=httpserver.go:146 msg="Web server shut down"
edgex-device-mqtt  | level=INFO ts=2024-09-04T16:52:38.587816644Z app=device-mqtt source=driver.go:223 msg="driver is stopping, disconnect the MQTT conn"
edgex-device-mqtt  | level=ERROR ts=2024-09-04T16:52:43.588950087Z app=device-mqtt source=bootstrap.go:27 msg="Device Service bootstrapping failed"