fix: change the ds-usb-camera executable to be docker-entrypoint-script - Githubissues

edgexfoundry / edgex-compose

EdgeX Foundry Docker Compose release compose files and tools for building EdgeX compose files

Apache License 2.0

81 stars 115 forks source link

fix: change the ds-usb-camera executable to be docker-entrypoint-script #378

Closed jim-wang-intel closed 1 year ago

jim-wang-intel commented 1 year ago

The device USB camera uses different normal executable like docker entrypoint shell script, so update the Makefile to adapt to this case

Fixes: #377

If your build fails due to your commit message not passing the build checks, please review the guidelines here: https://github.com/edgexfoundry/edgex-compose/blob/main/.github/Contributing.md

PR Checklist

Please check if your PR fulfills the following requirements:

[x] I am not introducing a breaking change (if you are, flag in conventional commit message with BREAKING CHANGE: describing the break)
[x] I have fully tested (add details below) this the new feature or bug fix (if not, why?)
[ ] I have opened a PR for the related docs change (if not, why?)

Testing Instructions

clone this pr
make sure you have an equivalent usb camera plug into the system
make clean
make pull ds-usb-camera
make run ds-usb-camera
observe the log of the ds-usb-camera service starts up correctly with docker logs edgex-device-usb-camera | grep docker-entrypoint

jim-wang-intel commented 1 year ago

Approved. Container still starts, but is crashing for other reasons:

panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x4878e2]

goroutine 1 [running]: sync.(WaitGroup).Add(0xc0000f4480?, 0xc000515998?) sync/waitgroup.go:52 +0x22 github.com/edgexfoundry/device-usb-camera/internal/driver.(Driver).Stop(0xc0004749a0, 0x68?) github.com/edgexfoundry/device-usb-camera/internal/driver/driver.go:267 +0xb8 github.com/edgexfoundry/device-sdk-go/v3/pkg/service.(deviceService).Stop(0xc000001ec0, 0x20?) github.com/edgexfoundry/device-sdk-go/v3@v3.0.0-dev.64/pkg/service/service.go:314 +0x2a github.com/edgexfoundry/device-sdk-go/v3/pkg/service.(deviceService).Run.func6() github.com/edgexfoundry/device-sdk-go/v3@v3.0.0-dev.64/pkg/service/service.go:166 +0x32 github.com/edgexfoundry/device-sdk-go/v3/pkg/service.(*deviceService).Run(0xc000001ec0) github.com/edgexfoundry/device-sdk-go/v3@v3.0.0-dev.64/pkg/service/service.go:171 +0xbfa github.com/edgexfoundry/device-sdk-go/v3/pkg/startup.Bootstrap({0xe07405?, 0xc16780?}, {0xf26960?, 0x0?}, {0xdb4320?, 0xc0004749a0?}) github.com/edgexfoundry/device-sdk-go/v3@v3.0.0-dev.64/pkg/startup/bootstrap.go:24 +0xa5 main.main() github.com/edgexfoundry/device-usb-camera/cmd/main.go:21 +0x45

interesting, i don't see that in the logs, maybe make sure you have cleaned up the volumes... make clean

ah, i think i have a realsense camera plugged-in and it found it so maybe you can find a usb camera and plugin

ajcasagrande commented 1 year ago

I can confirm the correct entrypoint is being generated in the docker compose file. I am looking into the issue on startup and recommend we delay the PR until resolved. Thanks for the quick work!

bnevis-i commented 1 year ago

IMO no reason to hold the PR. It's closer than it was.

ajcasagrande commented 1 year ago

IMO no reason to hold the PR. It's closer than it was.

Currently the service works, just the rtsp re-streaming feature does not. If the service is crashing altogether now, that isn't good.

Having said that, I am digging into it, because it seems like it crashed but then worked:

Script for waiting on security bootstrapping ready-to-run
Fri May 12 16:29:38 UTC 2023 Executing waitFor with /docker-entrypoint.sh -cp=consul.http://edgex-core-consul:8500 --registry waiting on tcp://edgex-security-bootstrapper:54329
level=INFO ts=2023-05-12T16:29:38.768728277Z app=security-bootstrapper source=config.go:636 msg="Loading configuration file from /edgex-init/res/configuration.yaml"
level=INFO ts=2023-05-12T16:29:38.768903734Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Database/Port' by environment variable: STAGEGATE_DATABASE_PORT=6379"
level=INFO ts=2023-05-12T16:29:38.768917156Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/WaitFor/Timeout' by environment variable: STAGEGATE_WAITFOR_TIMEOUT=60s"
level=INFO ts=2023-05-12T16:29:38.768921674Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Registry/ReadyPort' by environment variable: STAGEGATE_REGISTRY_READYPORT=54324"
level=INFO ts=2023-05-12T16:29:38.768924894Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/SecretStoreSetup/Host' by environment variable: STAGEGATE_SECRETSTORESETUP_HOST=edgex-security-secretstore-setup"
level=INFO ts=2023-05-12T16:29:38.768928896Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Registry/Host' by environment variable: STAGEGATE_REGISTRY_HOST=edgex-core-consul"
level=INFO ts=2023-05-12T16:29:38.768931514Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/BootStrapper/StartPort' by environment variable: STAGEGATE_BOOTSTRAPPER_STARTPORT=54321"
level=INFO ts=2023-05-12T16:29:38.768934437Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Registry/Port' by environment variable: STAGEGATE_REGISTRY_PORT=8500"
level=INFO ts=2023-05-12T16:29:38.768936886Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/BootStrapper/Host' by environment variable: STAGEGATE_BOOTSTRAPPER_HOST=edgex-security-bootstrapper"
level=INFO ts=2023-05-12T16:29:38.768940075Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Database/ReadyPort' by environment variable: STAGEGATE_DATABASE_READYPORT=6379"
level=INFO ts=2023-05-12T16:29:38.768942655Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Database/Host' by environment variable: STAGEGATE_DATABASE_HOST=edgex-redis"
level=INFO ts=2023-05-12T16:29:38.768945597Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Ready/ToRunPort' by environment variable: STAGEGATE_READY_TORUNPORT=54329"
level=INFO ts=2023-05-12T16:29:38.768948345Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/SecretStoreSetup/Tokens/ReadyPort' by environment variable: STAGEGATE_SECRETSTORESETUP_TOKENS_READYPORT=54322"
level=INFO ts=2023-05-12T16:29:38.768951323Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'SecretStore/Host' by environment variable: SECRETSTORE_HOST=edgex-vault"
level=INFO ts=2023-05-12T16:29:38.768954199Z app=security-bootstrapper source=config.go:222 msg="Private configuration loaded from file with 13 overrides applied"
level=INFO ts=2023-05-12T16:29:38.769086044Z app=security-bootstrapper source=command.go:119 msg="Security bootstrapper running waitFor"
level=INFO ts=2023-05-12T16:29:38.769108951Z app=security-bootstrapper source=command.go:144 msg="Waiting for: [tcp://edgex-security-bootstrapper:54329] with timeout: [1m0s]"
level=INFO ts=2023-05-12T16:29:38.770138156Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:39.771661488Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:40.77208755Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:41.773724062Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:42.774664958Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:43.776357715Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:44.77842597Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:45.779077625Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:46.779436197Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:47.781781576Z app=security-bootstrapper source=command.go:209 msg="Problem with dial: dial tcp 192.168.208.3:54329: connect: connection refused. Sleeping 1s"
level=INFO ts=2023-05-12T16:29:48.784034252Z app=security-bootstrapper source=command.go:214 msg="Connected to tcp://edgex-security-bootstrapper:54329"
Fri May 12 16:29:48 UTC 2023 Starting /docker-entrypoint.sh -cp=consul.http://edgex-core-consul:8500 --registry ...
Run rtsp-simple-server...
Run device-usb-camera...
level=INFO ts=2023-05-12T16:29:48.828779947Z app=device-usb-camera source=secret.go:69 msg="Creating SecretClient"
level=INFO ts=2023-05-12T16:29:48.829888648Z app=device-usb-camera source=variables.go:457 msg="Variables override of 'SecretStore/Host' by environment variable: SECRETSTORE_HOST=edgex-vault"
level=INFO ts=2023-05-12T16:29:48.829971913Z app=device-usb-camera source=secret.go:172 msg="SecretStore information created with 1 overrides applied"
level=INFO ts=2023-05-12T16:29:48.829980596Z app=device-usb-camera source=secret.go:79 msg="Reading secret store configuration and authentication token"
level=INFO ts=2023-05-12T16:29:48.829998111Z app=device-usb-camera source=secret.go:216 msg="load token from file"
level=INFO ts=2023-05-12T16:29:48.830074869Z app=device-usb-camera source=secret.go:101 msg="Attempting to create secret client"
level=INFO ts=2023-05-12T16:29:48.832527292Z app=device-usb-camera source=secret.go:112 msg="Created SecretClient"
level=INFO ts=2023-05-12T16:29:48.832544816Z app=device-usb-camera source=secret.go:117 msg="SecretsFile not set, skipping seeding of service secrets."
level=INFO ts=2023-05-12T16:29:48.832599163Z app=device-usb-camera source=secrets.go:277 msg="kick off token renewal with interval: 30m0s"
2023/05/12 16:29:48 INF MediaMTX / rtsp-simple-server v0.21.6
2023/05/12 16:29:48 INF [RTSP] listener opened on :8554 (TCP)
2023/05/12 16:29:48 INF [WebRTC] listener opened on :8889 (HTTP)
level=INFO ts=2023-05-12T16:29:48.865102259Z app=device-usb-camera source=secrets.go:149 msg="successfully generated Consul token for service device-usb-camera"
level=INFO ts=2023-05-12T16:29:48.865158856Z app=device-usb-camera source=config.go:625 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/core-common-config-bootstrapper/all-services"
level=INFO ts=2023-05-12T16:29:48.870360392Z app=device-usb-camera source=config.go:349 msg="loading the common configuration for service type device-service"
level=INFO ts=2023-05-12T16:29:48.894777691Z app=device-usb-camera source=secrets.go:149 msg="successfully generated Consul token for service device-usb-camera"
level=INFO ts=2023-05-12T16:29:48.894822972Z app=device-usb-camera source=config.go:625 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/core-common-config-bootstrapper/device-services"
level=INFO ts=2023-05-12T16:29:48.899498065Z app=device-usb-camera source=config.go:144 msg="Common configuration loaded from the Configuration Provider. No overrides applied"
level=INFO ts=2023-05-12T16:29:48.934191975Z app=device-usb-camera source=secrets.go:149 msg="successfully generated Consul token for service device-usb-camera"
level=INFO ts=2023-05-12T16:29:48.934316378Z app=device-usb-camera source=config.go:625 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/device-usb-camera"
level=INFO ts=2023-05-12T16:29:48.945872415Z app=device-usb-camera source=config.go:189 msg="Private configuration loaded from the Configuration Provider. No overrides applied"
level=INFO ts=2023-05-12T16:29:48.945986013Z app=device-usb-camera source=config.go:240 msg="listening for private config changes"
level=INFO ts=2023-05-12T16:29:48.946069958Z app=device-usb-camera source=config.go:242 msg="listening for all services common config changes"
level=INFO ts=2023-05-12T16:29:48.946109894Z app=device-usb-camera source=config.go:249 msg="listening for device service common config changes"
level=INFO ts=2023-05-12T16:29:48.986737449Z app=device-usb-camera source=secrets.go:149 msg="successfully generated Consul token for service device-usb-camera"
level=INFO ts=2023-05-12T16:29:48.986847611Z app=device-usb-camera source=registry.go:61 msg="Using Registry access token of length 36"
level=INFO ts=2023-05-12T16:29:48.986883488Z app=device-usb-camera source=registry.go:85 msg="Using Registry (consul) from http://edgex-core-consul:8500"
level=INFO ts=2023-05-12T16:29:49.047615783Z app=device-usb-camera source=httpserver.go:133 msg="Web server starting (edgex-device-usb-camera:59983)"
level=INFO ts=2023-05-12T16:29:49.047674728Z app=device-usb-camera source=messaging.go:66 msg="Setting options for secure MessageBus with AuthMode='usernamepassword' and SecretName='redisdb"
level=INFO ts=2023-05-12T16:29:49.049964136Z app=device-usb-camera source=messaging.go:104 msg="Connected to redis Message Bus @ redis://edgex-redis:6379 with AuthMode='usernamepassword'"
level=INFO ts=2023-05-12T16:29:49.049998613Z app=device-usb-camera source=command.go:34 msg="Subscribing to command requests on topic: edgex/device/command/request/device-usb-camera/#"
level=INFO ts=2023-05-12T16:29:49.050010482Z app=device-usb-camera source=command.go:37 msg="Responses to command requests will be published on topic: edgex/response/device-usb-camera/<requestId>"
level=INFO ts=2023-05-12T16:29:49.05088661Z app=device-usb-camera source=callback.go:33 msg="Subscribing to System Events on topic: edgex/system-events/core-metadata/+/+/device-usb-camera/#"
level=INFO ts=2023-05-12T16:29:49.052398648Z app=device-usb-camera source=validation.go:29 msg="Subscribing to device validation requests on topic: edgex/device-usb-camera/validate/device"
level=INFO ts=2023-05-12T16:29:49.05244092Z app=device-usb-camera source=validation.go:32 msg="Responses to device validation requests will be published on topic: edgex/response/device-usb-camera/<requestId>"
level=INFO ts=2023-05-12T16:29:49.05397277Z app=device-usb-camera source=manager.go:127 msg="Metrics Manager started with a report interval of 30s"
level=INFO ts=2023-05-12T16:29:49.056018343Z app=device-usb-camera source=clients.go:187 msg="Using registry for URL for 'core-metadata': http://edgex-core-metadata:59881"
level=INFO ts=2023-05-12T16:29:49.056198809Z app=device-usb-camera source=restrouter.go:57 msg="Registering v2 routes..."
level=ERROR ts=2023-05-12T16:29:49.062108684Z app=device-usb-camera source=init.go:53 msg="Failed to init cache: failed to send a http request -> Get \"http://edgex-core-metadata:59881/api/v3/device/service/name/device-usb-camera?limit=-1&offset=0\": dial tcp 192.168.208.15:59881: connect: connection refused"
level=INFO ts=2023-05-12T16:29:49.062201597Z app=device-usb-camera source=bootstrap.go:146 msg="Un-Registering service from the Registry"
level=INFO ts=2023-05-12T16:29:49.062252255Z app=device-usb-camera source=manager.go:109 msg="Exited Metrics Manager Run..."
level=INFO ts=2023-05-12T16:29:49.062329397Z app=device-usb-camera source=config.go:684 msg="Watching for 'Writable' configuration changes has stopped"
level=INFO ts=2023-05-12T16:29:49.062310836Z app=device-usb-camera source=config.go:746 msg="Watching for 'Writable' configuration changes has stopped"
level=INFO ts=2023-05-12T16:29:49.062265762Z app=device-usb-camera source=validation.go:53 msg="Exiting waiting for MessageBus 'edgex/device-usb-camera/validate/device' topic messages"
level=INFO ts=2023-05-12T16:29:49.062354597Z app=device-usb-camera source=messaging.go:95 msg="Disconnected from MessageBus"
level=INFO ts=2023-05-12T16:29:49.062355277Z app=device-usb-camera source=config.go:746 msg="Watching for 'Writable' configuration changes has stopped"
level=INFO ts=2023-05-12T16:29:49.062388534Z app=device-usb-camera source=httpserver.go:158 msg="Web server stopped"
level=INFO ts=2023-05-12T16:29:49.062381643Z app=device-usb-camera source=command.go:58 msg="Exiting waiting for MessageBus 'edgex/device/command/request/device-usb-camera/#' topic messages"
level=INFO ts=2023-05-12T16:29:49.06233605Z app=device-usb-camera source=callback.go:72 msg="Exiting waiting for MessageBus 'edgex/system-events/core-metadata/+/+/device-usb-camera/#' topic messages"
level=INFO ts=2023-05-12T16:29:49.062349377Z app=device-usb-camera source=secrets.go:285 msg="context cancelled, dismiss the token renewal process"
level=INFO ts=2023-05-12T16:29:49.062482585Z app=device-usb-camera source=httpserver.go:130 msg="Web server shut down"
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x4878e2]

goroutine 1 [running]:
sync.(*WaitGroup).Add(0x4?, 0xc000039e40?)
        sync/waitgroup.go:52 +0x22
github.com/edgexfoundry/device-usb-camera/internal/driver.(*Driver).Stop(0xc0004ae080, 0x8?)
        github.com/edgexfoundry/device-usb-camera/internal/driver/driver.go:368 +0x178
github.com/edgexfoundry/device-sdk-go/v3/pkg/service.(*deviceService).Stop(0xc0000ed8c0, 0x80?)
        github.com/edgexfoundry/device-sdk-go/v3@v3.0.0-dev.90/pkg/service/service.go:300 +0x2a
github.com/edgexfoundry/device-sdk-go/v3/pkg/service.(*deviceService).Run.func4()
        github.com/edgexfoundry/device-sdk-go/v3@v3.0.0-dev.90/pkg/service/service.go:148 +0x32
github.com/edgexfoundry/device-sdk-go/v3/pkg/service.(*deviceService).Run(0xc0000ed8c0)
        github.com/edgexfoundry/device-sdk-go/v3@v3.0.0-dev.90/pkg/service/service.go:153 +0xc05
github.com/edgexfoundry/device-sdk-go/v3/pkg/startup.Bootstrap({0xe0a09b, 0x11}, {0xf29708, 0xc}, {0xf396d0?, 0xc0004ae080})
        github.com/edgexfoundry/device-sdk-go/v3@v3.0.0-dev.90/pkg/startup/bootstrap.go:25 +0x247
main.main()
        github.com/edgexfoundry/device-usb-camera/cmd/main.go:21 +0x45
Script for waiting on security bootstrapping ready-to-run
Fri May 12 16:29:50 UTC 2023 Executing waitFor with /docker-entrypoint.sh -cp=consul.http://edgex-core-consul:8500 --registry waiting on tcp://edgex-security-bootstrapper:54329
level=INFO ts=2023-05-12T16:29:50.140879592Z app=security-bootstrapper source=config.go:636 msg="Loading configuration file from /edgex-init/res/configuration.yaml"
level=INFO ts=2023-05-12T16:29:50.141057052Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/SecretStoreSetup/Host' by environment variable: STAGEGATE_SECRETSTORESETUP_HOST=edgex-security-secretstore-setup"
level=INFO ts=2023-05-12T16:29:50.141069466Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Ready/ToRunPort' by environment variable: STAGEGATE_READY_TORUNPORT=54329"
level=INFO ts=2023-05-12T16:29:50.141072612Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'SecretStore/Host' by environment variable: SECRETSTORE_HOST=edgex-vault"
level=INFO ts=2023-05-12T16:29:50.141075903Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Registry/Host' by environment variable: STAGEGATE_REGISTRY_HOST=edgex-core-consul"
level=INFO ts=2023-05-12T16:29:50.141078534Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Database/Port' by environment variable: STAGEGATE_DATABASE_PORT=6379"
level=INFO ts=2023-05-12T16:29:50.14108114Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Registry/ReadyPort' by environment variable: STAGEGATE_REGISTRY_READYPORT=54324"
level=INFO ts=2023-05-12T16:29:50.141083827Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/SecretStoreSetup/Tokens/ReadyPort' by environment variable: STAGEGATE_SECRETSTORESETUP_TOKENS_READYPORT=54322"
level=INFO ts=2023-05-12T16:29:50.141086689Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/BootStrapper/StartPort' by environment variable: STAGEGATE_BOOTSTRAPPER_STARTPORT=54321"
level=INFO ts=2023-05-12T16:29:50.14109143Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Registry/Port' by environment variable: STAGEGATE_REGISTRY_PORT=8500"
level=INFO ts=2023-05-12T16:29:50.141093969Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/WaitFor/Timeout' by environment variable: STAGEGATE_WAITFOR_TIMEOUT=60s"
level=INFO ts=2023-05-12T16:29:50.141096766Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Database/ReadyPort' by environment variable: STAGEGATE_DATABASE_READYPORT=6379"
level=INFO ts=2023-05-12T16:29:50.141099223Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/Database/Host' by environment variable: STAGEGATE_DATABASE_HOST=edgex-redis"
level=INFO ts=2023-05-12T16:29:50.141102353Z app=security-bootstrapper source=variables.go:457 msg="Variables override of 'StageGate/BootStrapper/Host' by environment variable: STAGEGATE_BOOTSTRAPPER_HOST=edgex-security-bootstrapper"
level=INFO ts=2023-05-12T16:29:50.141105194Z app=security-bootstrapper source=config.go:222 msg="Private configuration loaded from file with 13 overrides applied"
level=INFO ts=2023-05-12T16:29:50.141237193Z app=security-bootstrapper source=command.go:119 msg="Security bootstrapper running waitFor"
level=INFO ts=2023-05-12T16:29:50.141259805Z app=security-bootstrapper source=command.go:144 msg="Waiting for: [tcp://edgex-security-bootstrapper:54329] with timeout: [1m0s]"
level=INFO ts=2023-05-12T16:29:50.142233519Z app=security-bootstrapper source=command.go:214 msg="Connected to tcp://edgex-security-bootstrapper:54329"
Fri May 12 16:29:50 UTC 2023 Starting /docker-entrypoint.sh -cp=consul.http://edgex-core-consul:8500 --registry ...
Run rtsp-simple-server...
Run device-usb-camera...
level=INFO ts=2023-05-12T16:29:50.147096818Z app=device-usb-camera source=secret.go:69 msg="Creating SecretClient"
level=INFO ts=2023-05-12T16:29:50.147625965Z app=device-usb-camera source=variables.go:457 msg="Variables override of 'SecretStore/Host' by environment variable: SECRETSTORE_HOST=edgex-vault"
level=INFO ts=2023-05-12T16:29:50.147676958Z app=device-usb-camera source=secret.go:172 msg="SecretStore information created with 1 overrides applied"
level=INFO ts=2023-05-12T16:29:50.147684378Z app=device-usb-camera source=secret.go:79 msg="Reading secret store configuration and authentication token"
level=INFO ts=2023-05-12T16:29:50.147702551Z app=device-usb-camera source=secret.go:216 msg="load token from file"
level=INFO ts=2023-05-12T16:29:50.147771469Z app=device-usb-camera source=secret.go:101 msg="Attempting to create secret client"
level=INFO ts=2023-05-12T16:29:50.149021495Z app=device-usb-camera source=secret.go:112 msg="Created SecretClient"
level=INFO ts=2023-05-12T16:29:50.149033102Z app=device-usb-camera source=secret.go:117 msg="SecretsFile not set, skipping seeding of service secrets."
level=INFO ts=2023-05-12T16:29:50.149109216Z app=device-usb-camera source=secrets.go:277 msg="kick off token renewal with interval: 30m0s"
2023/05/12 16:29:50 INF MediaMTX / rtsp-simple-server v0.21.6
2023/05/12 16:29:50 INF [RTSP] listener opened on :8554 (TCP)
2023/05/12 16:29:50 INF [WebRTC] listener opened on :8889 (HTTP)
level=INFO ts=2023-05-12T16:29:50.164847449Z app=device-usb-camera source=secrets.go:149 msg="successfully generated Consul token for service device-usb-camera"
level=INFO ts=2023-05-12T16:29:50.164895999Z app=device-usb-camera source=config.go:625 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/core-common-config-bootstrapper/all-services"
level=INFO ts=2023-05-12T16:29:50.167492747Z app=device-usb-camera source=config.go:349 msg="loading the common configuration for service type device-service"
level=INFO ts=2023-05-12T16:29:50.181665412Z app=device-usb-camera source=secrets.go:149 msg="successfully generated Consul token for service device-usb-camera"
level=INFO ts=2023-05-12T16:29:50.181687488Z app=device-usb-camera source=config.go:625 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/core-common-config-bootstrapper/device-services"
level=INFO ts=2023-05-12T16:29:50.183805883Z app=device-usb-camera source=config.go:144 msg="Common configuration loaded from the Configuration Provider. No overrides applied"
level=INFO ts=2023-05-12T16:29:50.197724478Z app=device-usb-camera source=secrets.go:149 msg="successfully generated Consul token for service device-usb-camera"
level=INFO ts=2023-05-12T16:29:50.197751438Z app=device-usb-camera source=config.go:625 msg="Using Configuration provider (consul) from: http://edgex-core-consul:8500 with base path of edgex/v3/device-usb-camera"
level=INFO ts=2023-05-12T16:29:50.200039814Z app=device-usb-camera source=config.go:189 msg="Private configuration loaded from the Configuration Provider. No overrides applied"
level=INFO ts=2023-05-12T16:29:50.200055555Z app=device-usb-camera source=config.go:240 msg="listening for private config changes"
level=INFO ts=2023-05-12T16:29:50.200063952Z app=device-usb-camera source=config.go:242 msg="listening for all services common config changes"
level=INFO ts=2023-05-12T16:29:50.200068285Z app=device-usb-camera source=config.go:249 msg="listening for device service common config changes"
level=INFO ts=2023-05-12T16:29:50.214118553Z app=device-usb-camera source=secrets.go:149 msg="successfully generated Consul token for service device-usb-camera"
level=INFO ts=2023-05-12T16:29:50.214139897Z app=device-usb-camera source=registry.go:61 msg="Using Registry access token of length 36"
level=INFO ts=2023-05-12T16:29:50.214144562Z app=device-usb-camera source=registry.go:85 msg="Using Registry (consul) from http://edgex-core-consul:8500"
level=INFO ts=2023-05-12T16:29:50.266400966Z app=device-usb-camera source=httpserver.go:133 msg="Web server starting (edgex-device-usb-camera:59983)"
level=INFO ts=2023-05-12T16:29:50.266431271Z app=device-usb-camera source=messaging.go:66 msg="Setting options for secure MessageBus with AuthMode='usernamepassword' and SecretName='redisdb"
level=INFO ts=2023-05-12T16:29:50.267077381Z app=device-usb-camera source=messaging.go:104 msg="Connected to redis Message Bus @ redis://edgex-redis:6379 with AuthMode='usernamepassword'"
level=INFO ts=2023-05-12T16:29:50.267087167Z app=device-usb-camera source=command.go:34 msg="Subscribing to command requests on topic: edgex/device/command/request/device-usb-camera/#"
level=INFO ts=2023-05-12T16:29:50.267091486Z app=device-usb-camera source=command.go:37 msg="Responses to command requests will be published on topic: edgex/response/device-usb-camera/<requestId>"
level=INFO ts=2023-05-12T16:29:50.267617695Z app=device-usb-camera source=callback.go:33 msg="Subscribing to System Events on topic: edgex/system-events/core-metadata/+/+/device-usb-camera/#"
level=INFO ts=2023-05-12T16:29:50.267906281Z app=device-usb-camera source=validation.go:29 msg="Subscribing to device validation requests on topic: edgex/device-usb-camera/validate/device"
level=INFO ts=2023-05-12T16:29:50.267924813Z app=device-usb-camera source=validation.go:32 msg="Responses to device validation requests will be published on topic: edgex/response/device-usb-camera/<requestId>"
level=INFO ts=2023-05-12T16:29:50.268173128Z app=device-usb-camera source=manager.go:127 msg="Metrics Manager started with a report interval of 30s"
level=INFO ts=2023-05-12T16:29:50.268585725Z app=device-usb-camera source=clients.go:187 msg="Using registry for URL for 'core-metadata': http://edgex-core-metadata:59881"
level=INFO ts=2023-05-12T16:29:50.268601792Z app=device-usb-camera source=restrouter.go:57 msg="Registering v2 routes..."
level=INFO ts=2023-05-12T16:29:50.27703546Z app=device-usb-camera source=driver.go:100 msg="RTSP server hostname: localhost"
level=INFO ts=2023-05-12T16:29:50.277053073Z app=device-usb-camera source=driver.go:108 msg="RTSP TCP port: 8554"
level=INFO ts=2023-05-12T16:29:50.277055859Z app=device-usb-camera source=driver.go:116 msg="RtspAuthenticationServer: localhost:8000"
level=INFO ts=2023-05-12T16:29:50.279178516Z app=device-usb-camera source=service.go:279 msg="device service device-usb-camera exists, updating it"
level=INFO ts=2023-05-12T16:29:50.281352885Z app=device-usb-camera source=profiles.go:56 msg="Loading pre-defined profiles from /res/profiles(3 files found)"
level=INFO ts=2023-05-12T16:29:50.283849349Z app=device-usb-camera source=profiles.go:93 msg="Profile USB-Camera-General exists, using the existing one"
level=INFO ts=2023-05-12T16:29:50.283899203Z app=device-usb-camera source=devices.go:54 msg="Loading pre-defined devices from /res/devices(2 files found)"
level=INFO ts=2023-05-12T16:29:50.283916543Z app=device-usb-camera source=provisionwatchers.go:47 msg="Loading pre-defined provision watchers from /res/provisionwatchers(1 files found)"
level=INFO ts=2023-05-12T16:29:50.284002784Z app=device-usb-camera source=provisionwatchers.go:82 msg="ProvisionWatcher USB-Camera-Provision-Watcher exists, using the existing one"
level=INFO ts=2023-05-12T16:29:50.284018865Z app=device-usb-camera source=message.go:50 msg="Service dependencies resolved..."
level=INFO ts=2023-05-12T16:29:50.284024322Z app=device-usb-camera source=message.go:51 msg="Starting device-usb-camera 3.0.0-dev.41 "
level=INFO ts=2023-05-12T16:29:50.284027731Z app=device-usb-camera source=message.go:55 msg="device-usb-camera started"
level=INFO ts=2023-05-12T16:29:50.284032233Z app=device-usb-camera source=message.go:58 msg="Service started in: 137.242636ms"
level=INFO ts=2023-05-12T16:29:50.284044097Z app=device-usb-camera source=bootstrap.go:251 msg="SecurityGetSecretDuration metric registered and will be reported (if enabled)"
level=INFO ts=2023-05-12T16:29:50.284048339Z app=device-usb-camera source=bootstrap.go:251 msg="SecuritySecretsRequested metric registered and will be reported (if enabled)"
level=INFO ts=2023-05-12T16:29:50.284050616Z app=device-usb-camera source=bootstrap.go:251 msg="SecuritySecretsStored metric registered and will be reported (if enabled)"
level=INFO ts=2023-05-12T16:29:50.284052704Z app=device-usb-camera source=bootstrap.go:251 msg="SecurityConsulTokensRequested metric registered and will be reported (if enabled)"
level=INFO ts=2023-05-12T16:29:50.284054943Z app=device-usb-camera source=bootstrap.go:251 msg="SecurityConsulTokenDuration metric registered and will be reported (if enabled)"
level=INFO ts=2023-05-12T16:29:50.284057362Z app=device-usb-camera source=bootstrap.go:251 msg="SecurityRuntimeSecretTokenDuration metric registered and will be reported (if enabled)"
level=INFO ts=2023-05-12T16:29:50.284059661Z app=device-usb-camera source=driver.go:127 msg="Initializing cameras..."
level=INFO ts=2023-05-12T16:29:50.284063579Z app=device-usb-camera source=driver.go:129 msg="initialize device HD_Pro_Webcam_C920-DD603BAF"
level=INFO ts=2023-05-12T16:29:50.284090177Z app=device-usb-camera source=autodiscovery.go:46 msg="Starting auto-discovery with duration 1h0m0s"
level=INFO ts=2023-05-12T16:29:50.284101145Z app=device-usb-camera source=driver.go:479 msg="Discovery is triggered"
level=ERROR ts=2023-05-12T16:29:50.284475465Z app=device-usb-camera source=credentials.go:25 msg="Failed to retrieve credentials for the secret path rtspauth: Error retreiving secret secretName: 'Received a '404' response from the secret store'"
level=WARN ts=2023-05-12T16:29:50.284489553Z app=device-usb-camera source=driver.go:645 msg="Failed to retrieve credentials for rtsp authentication from the secret store. Have you stored credentials yet for secretName rtspauth?"
level=WARN ts=2023-05-12T16:29:51.373462208Z app=device-usb-camera source=driver.go:574 msg="Protocol property AutoStreaming not found. Use default value: false"
level=INFO ts=2023-05-12T16:29:51.377549045Z app=device-usb-camera source=driver.go:156 msg="Starting rtsp server"

ajcasagrande commented 1 year ago

After reviewing the logs, it appears the crash was past of EdgeX bootstrapping, and it fixed itself. The panic is a bug with the shutting down of the web server.

I ran make clean and ran again with no errors this time. Approve of merging. Thanks again.

ajcasagrande commented 1 year ago

I was able to successfully run StartStreaming and have it utilize the rtsp-simple-server just like it works in non-secure mode. This should be able to close the related issue: https://github.com/edgexfoundry/device-usb-camera/issues/236

ajcasagrande commented 1 year ago

@jim-wang-intel can this be merged?

vyshali-chitikeshi commented 1 year ago

Validation also looks good in secure mode.