level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="iot_threadpool_alloc (threads: 8 max_jobs: 0 default_priority: -1 affinity: -1)"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="iot_scheduler_alloc (priority: -1 affinity: -1)"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="Setting LogLevel to TRACE"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="Starting device-template device service, version 1.0"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="EdgeX device SDK for C, version 3.2.0"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service configuration follows:"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/DataTransform=true"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/DevicesDir="./res/devices""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/Discovery/Enabled=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/Discovery/Interval=0"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/EventQLength=0"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/Labels=[]"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/MaxCmdOps=128"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/ProfilesDir="./res/profiles""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device/UpdateLastConnected=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Driver/TestParam1="X""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MaxEventSize=0"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/AuthMode="none""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/BaseTopicPrefix="edgex""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Disabled=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Host="localhost""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Optional/CertFile="""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Optional/ClientId="device-example""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Optional/KeepAlive=60"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Optional/KeyFile="""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Optional/Qos=0"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Optional/Retained=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Optional/SkipCertVerify=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Port=1883"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Protocol="tcp""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/SecretName="mqtt-bus""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="MessageBus/Type="mqtt""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/Authentication/AuthType="X-Vault-Token""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/DisableScrubSecretsFile=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/Host="localhost""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/Path="device-template/""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/Port=8200"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/Protocol="http""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/RootCaCertPath="""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/SecretsFile="""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/ServerName="""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/TokenFile="/tmp/edgex/secrets/device-template/secrets-token.json""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="SecretStore/Type="vault""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/CORSConfiguration/CORSAllowCredentials=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/CORSConfiguration/CORSAllowedHeaders="Authorization, Accept, Accept-Language, Content-Language, Content-Type, X-Correlation-ID""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/CORSConfiguration/CORSAllowedMethods="GET, POST, PUT, PATCH, DELETE""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/CORSConfiguration/CORSAllowedOrigin="https://localhost""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/CORSConfiguration/CORSExposeHeaders="Cache-Control, Content-Language, Content-Length, Content-Type, Expires, Last-Modified, Pragma, X-Correlation-ID""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/CORSConfiguration/CORSMaxAge=3600"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/CORSConfiguration/EnableCORS=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/HealthCheckInterval="10s""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/Host="localhost""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/MaxRequestSize=0"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/Port=59999"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/RequestTimeout="5s""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/ServerBindAddr="""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Service/StartupMsg="device simple started""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Driver/TestParam2="Y""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Driver/TestParam3="Z""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/InsecureSecrets/DB/SecretData/password="""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/InsecureSecrets/DB/SecretData/username="""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/InsecureSecrets/DB/SecretName="redisdb""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/LogLevel="TRACE""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Telemetry/Interval="30s""
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Telemetry/Metrics/EventsSent=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Telemetry/Metrics/ReadCommandsExecuted=true"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Telemetry/Metrics/ReadingsSent=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Telemetry/Metrics/SecuritySecretsRequested=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Telemetry/Metrics/SecuritySecretsStored=false"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Writable/Telemetry/PublishTopicPrefix="edgex/telemetry""
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="iot_threadpool_alloc (threads: 1 max_jobs: 0 default_priority: -1 affinity: -1)"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Thread iot-1-0 #0 starting"
level=TRACE ts=2024-08-14T17:47:32Z app=device-template msg="iot_threadpool_start"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="Message Bus is set to MQTT at tcp://localhost:1883"
level=TRACE ts=2024-08-14T17:47:32Z app=device-template msg="Thread 0 waiting for new job"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="mqtt: connected"
level=TRACE ts=2024-08-14T17:47:32Z app=device-template msg="GET to http://localhost:59881/api/v3/ping returns 200 (no data)"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="Found core-metadata service at localhost:59881"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="HTTP response: 404"
level=TRACE ts=2024-08-14T17:47:32Z app=device-template msg="GET to http://localhost:59881/api/v3/deviceservice/name/device-template returns 404, data {"apiVersion":"v3","message":"fail to query device service by name device-template","statusCode":404}
"
level=TRACE ts=2024-08-14T17:47:32Z app=device-template msg="POST [{"apiVersion":"v3","Service":{"apiVersion":"v3","baseaddress":"http://localhost:59999","adminState":"UNLOCKED","labels":[],"name":"device-template","origin":1723657652225}}] to http://localhost:59881/api/v3/deviceservice returns 207"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="Processing Device Profiles from ./res/profiles"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Checking existence of DeviceProfile RandNum-Device"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="HTTP response: 404"
level=TRACE ts=2024-08-14T17:47:32Z app=device-template msg="GET to http://localhost:59881/api/v3/deviceprofile/name/RandNum-Device returns 404, data {"apiVersion":"v3","message":"fail to query device profile by name RandNum-Device","statusCode":404}
"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="Uploading deviceprofile from ./res/profiles/random-generator.yaml"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Device profile upload successful, will now retrieve it"
level=TRACE ts=2024-08-14T17:47:32Z app=device-template msg="GET to http://localhost:59881/api/v3/deviceprofile/name/RandNum-Device returns 200, data {"apiVersion":"v3","statusCode":200,"profile":{"created":1723657652233,"modified":1723657652233,"id":"317addcf-69a3-42c9-96b4-bc36228e63d9","name":"RandNum-Device","manufacturer":"Dell Technologies","description":"random number generator to simulate a device","model":"1","labels":["random","test"],"deviceResources":[{"description":"generated random number","name":"RandomNumber","isHidden":false,"properties":{"valueType":"Int32","readWrite":"R"},"attributes":{"type":"random"}}],"deviceCommands":[]}}
"
level=TRACE ts=2024-08-14T17:47:32Z app=device-template msg="GET to http://localhost:59881/api/v3/device/service/name/device-template returns 200, data {"apiVersion":"v3","statusCode":200,"totalCount":0,"devices":[]}
"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="Starting HTTP server on interface localhost, port 59999"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="Resolved interface is ::1"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="mqtt: subscribing to edgex/system-events/core-metadata/device/add/device-template/#"
level=DEBUG ts=2024-08-14T17:47:32Z app=device-template msg="mqtt: subscribing to edgex/device-template/validate/device"
level=INFO ts=2024-08-14T17:47:32Z app=device-template msg="Processing Devices from ./res/devices"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="HTTP response: 503"
level=TRACE ts=2024-08-14T17:47:37Z app=device-template msg="POST [{"apiVersion":"v3","Device":{"name":"RandNum-Device01","profileName":"RandNum-Device","description":"Random Number Generator Device","labels":["test","random"],"protocols":{"Other":{"Address":"random","Port":300}},"autoEvents":[{"interval":"10s","sourceName":"RandomNumber","onChange":false}],"serviceName":"device-template","adminState":"UNLOCKED","operatingState":"UP","apiVersion":"v3"}}] to http://localhost:59881/api/v3/device returns 503"
level=INFO ts=2024-08-14T17:47:37Z app=device-template msg="Device RandNum-Device01 create failed: HTTP request failed: <html><head><title>Timeout</title></head><body><h1>Timeout</h1></body></html>"
level=ERROR ts=2024-08-14T17:47:37Z app=device-template msg="Error processing file ./res/devices/random-generator-devices.json"
Error: 21: HTTP request failed
level=TRACE ts=2024-08-14T17:47:37Z app=device-template msg="iot_scheduler_free"
level=TRACE ts=2024-08-14T17:47:37Z app=device-template msg="iot_threadpool_free"
level=TRACE ts=2024-08-14T17:47:37Z app=device-template msg="iot_threadpool_stop"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 3 exiting"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 6 exiting"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 2 exiting"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 5 exiting"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 4 exiting"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 1 exiting"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 0 exiting"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 7 exiting"
level=TRACE ts=2024-08-14T17:47:37Z app=device-template msg="iot_threadpool_free"
level=TRACE ts=2024-08-14T17:47:37Z app=device-template msg="iot_threadpool_stop"
level=DEBUG ts=2024-08-14T17:47:37Z app=device-template msg="Thread 0 exiting"