retry_timing_bug.log

level=INFO ts=2021-06-29T23:52:22.565761055Z app=edgex-device-rfid-llrp source=config.go:193 msg="Loaded configuration from res/configuration.toml"
level=INFO ts=2021-06-29T23:52:22.566331554Z app=edgex-device-rfid-llrp source=config.go:168 msg="Using Configuration provider (consul) from: http://localhost:8500 with base path of edgex/devices/1.0/edgex-device-rfid-llrp"
level=INFO ts=2021-06-29T23:52:22.570492724Z app=edgex-device-rfid-llrp source=config.go:304 msg="Configuration has been pulled from Configuration provider (0 envVars overrides applied)"
level=INFO ts=2021-06-29T23:52:22.57057569Z app=edgex-device-rfid-llrp source=httpserver.go:99 msg="Web server starting (10.0.0.53:49989)"
level=INFO ts=2021-06-29T23:52:22.570618151Z app=edgex-device-rfid-llrp source=init.go:144 msg="Check Metadata service's status by ping..."
level=INFO ts=2021-06-29T23:52:22.570737224Z app=edgex-device-rfid-llrp source=init.go:144 msg="Check Data service's status by ping..."
level=INFO ts=2021-06-29T23:52:22.572134314Z app=edgex-device-rfid-llrp source=init.go:68 msg="Service clients initialize successful."
level=INFO ts=2021-06-29T23:52:22.57361032Z app=edgex-device-rfid-llrp source=service.go:224 msg="Addressable edgex-device-rfid-llrp exists, updating it"
level=DEBUG ts=2021-06-29T23:52:22.574576655Z app=edgex-device-rfid-llrp source=service.go:155 msg="Trying to find DeviceService: edgex-device-rfid-llrp"
level=INFO ts=2021-06-29T23:52:22.57526455Z app=edgex-device-rfid-llrp source=service.go:177 msg="DeviceService edgex-device-rfid-llrp exists, updating it"
level=DEBUG ts=2021-06-29T23:52:22.583991317Z app=edgex-device-rfid-llrp source=driver.go:164 msg="&{DiscoverySubnets:10.0.0.0/24 ProbeAsyncLimit:4000 ProbeTimeoutSeconds:2 ScanPort:5084 MaxDiscoverDurationSeconds:300}"
level=INFO ts=2021-06-29T23:52:22.584113532Z app=edgex-device-rfid-llrp source=driver.go:186 deviceName=SpeedwayR-11-25-D6 msg="Creating a new Reader connection."
level=INFO ts=2021-06-29T23:52:22.584190981Z app=edgex-device-rfid-llrp source=driver.go:229 msg="watching for configuration changes..."
level=DEBUG ts=2021-06-29T23:52:22.584253695Z app=edgex-device-rfid-llrp source=device.go:124 device=SpeedwayR-11-25-D6 msg="Starting Reader management."
level=DEBUG ts=2021-06-29T23:52:22.584275065Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=INFO ts=2021-06-29T23:52:22.584409711Z app=edgex-device-rfid-llrp source=restrouter.go:75 msg="Registering v2 routes..."
level=DEBUG ts=2021-06-29T23:52:22.584419139Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:52:22.584577459Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:22.584603858Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=ERROR ts=2021-06-29T23:52:22.584672857Z app=edgex-device-rfid-llrp source=device.go:166 error="reader is already connected to another client" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
level=DEBUG ts=2021-06-29T23:52:22.584759594Z app=edgex-device-rfid-llrp source=profiles.go:47 msg="created absolute path for loading pre-defined Device Profiles: /opt/intel/projects/device-rfid-llrp-go/cmd/res"
2021/06/29 16:52:22 retry attempt: 1, wait: 0s
level=DEBUG ts=2021-06-29T23:52:22.584809598Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:52:22.585006049Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:52:22.585111852Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=97322b9c-a941-4caa-9d9d-e4513483feb0 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:52:22.585155151Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:52:22.585204247Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:22.585226455Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=ERROR ts=2021-06-29T23:52:22.585262072Z app=edgex-device-rfid-llrp source=device.go:166 error="reader is already connected to another client" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
2021/06/29 16:52:22 retry attempt: 1, wait: 5s
level=INFO ts=2021-06-29T23:52:22.585389944Z app=edgex-device-rfid-llrp source=driver.go:244 msg="driver configuration has been updated!"
level=DEBUG ts=2021-06-29T23:52:22.588670678Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:52:22.588779904Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=05c27a7c-9597-4fb9-a7c4-084870ae925a msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:52:22.588816009Z app=edgex-device-rfid-llrp source=driver.go:245 msg="raw: &{DiscoverySubnets:10.0.0.0/24 ProbeAsyncLimit:4000 ProbeTimeoutSeconds:2 ScanPort:5084 MaxDiscoverDurationSeconds:300}"
level=DEBUG ts=2021-06-29T23:52:22.588859448Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=97322b9c-a941-4caa-9d9d-e4513483feb0 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:52:22.589614037Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=05c27a7c-9597-4fb9-a7c4-084870ae925a msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:52:22.594753974Z app=edgex-device-rfid-llrp source=devices.go:29 msg="Loading pre-define Devices from configuration"
level=INFO ts=2021-06-29T23:52:22.594795597Z app=edgex-device-rfid-llrp source=message.go:50 msg="Service dependencies resolved..."
level=INFO ts=2021-06-29T23:52:22.594810821Z app=edgex-device-rfid-llrp source=message.go:51 msg="Starting edgex-device-rfid-llrp 0.0.0 "
level=INFO ts=2021-06-29T23:52:22.594821227Z app=edgex-device-rfid-llrp source=message.go:55 msg="device llrp started"
level=INFO ts=2021-06-29T23:52:22.59483275Z app=edgex-device-rfid-llrp source=message.go:58 msg="Service started in: 29.473468ms"
level=INFO ts=2021-06-29T23:52:22.594858311Z app=edgex-device-rfid-llrp source=autodiscovery.go:50 msg="Starting auto-discovery with duration 1h0m0s"
level=DEBUG ts=2021-06-29T23:52:22.594870113Z app=edgex-device-rfid-llrp source=discovery.go:34 msg="protocol discovery triggered"
level=INFO ts=2021-06-29T23:52:22.59487989Z app=edgex-device-rfid-llrp source=driver.go:845 msg="Discover was called."
level=DEBUG ts=2021-06-29T23:52:22.594903914Z app=edgex-device-rfid-llrp source=discover.go:117 msg="total estimated network probes: 254, async limit: 254, probe timeout: 2s, total estimated time: 2s"
level=INFO ts=2021-06-29T23:52:22.63079841Z app=edgex-device-rfid-llrp source=discover.go:457 address=10.0.0.53:5084 deviceName=SpeedwayR-11-25-D6 msg="Existing device in disabled (disconnected) state will be scanned again."
level=INFO ts=2021-06-29T23:52:22.631015742Z app=edgex-device-rfid-llrp source=discover.go:341 host=10.0.0.53 port=5084 msg="Connection dialed"
level=INFO ts=2021-06-29T23:52:22.631073149Z app=edgex-device-rfid-llrp source=discover.go:389 host=10.0.0.53 port=5084 msg="Attempting to connect to potential LLRP device..."
level=DEBUG ts=2021-06-29T23:52:22.631119381Z app=edgex-device-rfid-llrp source=discover.go:362 msg="Sending GetReaderConfig."
level=INFO ts=2021-06-29T23:52:22.631163657Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=probe-10.0.0.53 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:22.631187751Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=WARN ts=2021-06-29T23:52:22.631225603Z app=edgex-device-rfid-llrp source=discover.go:392 msg="Error attempting to connect to potential LLRP device: reader is already connected to another client"
level=WARN ts=2021-06-29T23:52:22.63137673Z app=edgex-device-rfid-llrp source=discover.go:368 error="message not sent: client closed" msg="Client connection was closed while sending GetReaderConfig to discovered device."
level=INFO ts=2021-06-29T23:52:24.666802288Z app=edgex-device-rfid-llrp source=driver.go:898 msg="Discovered 0 new devices in 2.071855076s."
level=DEBUG ts=2021-06-29T23:52:24.666884556Z app=edgex-device-rfid-llrp source=async.go:164 msg="Filtered device addition finished"
level=DEBUG ts=2021-06-29T23:52:27.586015115Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:52:27.586385391Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:52:27.586696166Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:27.586745471Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=ERROR ts=2021-06-29T23:52:27.586814261Z app=edgex-device-rfid-llrp source=device.go:166 error="reader is already connected to another client" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
2021/06/29 16:52:27 retry attempt: 1, wait: 50ms
level=DEBUG ts=2021-06-29T23:52:27.586976701Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:52:27.587049821Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=cda41364-ae76-47d5-82a5-5aa85cfb3922 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:52:27.588759013Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=cda41364-ae76-47d5-82a5-5aa85cfb3922 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:52:27.637044696Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:52:27.637432361Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:52:27.637666944Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:27.637743555Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=ERROR ts=2021-06-29T23:52:27.637832527Z app=edgex-device-rfid-llrp source=device.go:166 error="reader is already connected to another client" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
2021/06/29 16:52:27 retry attempt: 2, wait: 15s
level=DEBUG ts=2021-06-29T23:52:27.63806725Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:52:27.638171935Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=e9b29e9c-b1d8-4ff8-ab11-b70715bb4a0c msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:52:27.639819741Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=e9b29e9c-b1d8-4ff8-ab11-b70715bb4a0c msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:52:42.641080288Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:52:42.641569426Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:52:42.641943404Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:42.642000111Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=ERROR ts=2021-06-29T23:52:42.642081541Z app=edgex-device-rfid-llrp source=device.go:166 error="reader is already connected to another client" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
2021/06/29 16:52:42 retry attempt: 1, wait: 50ms
level=DEBUG ts=2021-06-29T23:52:42.642367524Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:52:42.642478984Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=8e81a06e-7896-41eb-a394-344683f368eb msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:52:42.645018259Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=8e81a06e-7896-41eb-a394-344683f368eb msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:52:42.693436355Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:52:42.693912364Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:52:42.69406824Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:42.694120827Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=ERROR ts=2021-06-29T23:52:42.694187801Z app=edgex-device-rfid-llrp source=device.go:166 error="reader is already connected to another client" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
2021/06/29 16:52:42 retry attempt: 3, wait: 0s
level=DEBUG ts=2021-06-29T23:52:42.694370216Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:52:42.694396474Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:52:42.69446247Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=e531feaa-3d9a-4820-b2af-bf9e530d1f38 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:52:42.694806138Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:52:42.695039324Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:42.695100571Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=ERROR ts=2021-06-29T23:52:42.695164891Z app=edgex-device-rfid-llrp source=device.go:166 error="reader is already connected to another client" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
2021/06/29 16:52:42 retry attempt: 1, wait: 0s
level=DEBUG ts=2021-06-29T23:52:42.695395074Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:52:42.695404851Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:52:42.695512261Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=45cb8692-d158-429a-8301-821dd18aab62 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:52:42.695703056Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:52:42.695876321Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:52:42.695928001Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=ERROR ts=2021-06-29T23:52:42.696005101Z app=edgex-device-rfid-llrp source=device.go:166 error="reader is already connected to another client" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
2021/06/29 16:52:42 retry attempt: 4, wait: 20s
level=DEBUG ts=2021-06-29T23:52:42.696145892Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:52:42.696243175Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=4342c86a-6095-4f28-8724-8ea888e79d5c msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:52:42.696505553Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=e531feaa-3d9a-4820-b2af-bf9e530d1f38 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:52:42.697399537Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=45cb8692-d158-429a-8301-821dd18aab62 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:52:42.697704446Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=4342c86a-6095-4f28-8724-8ea888e79d5c msg="SendEvent: Pushed event to core data"



level=DEBUG ts=2021-06-29T23:53:02.710888825Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:53:02.711299048Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:53:02.71200971Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:53:02.712061529Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=INFO ts=2021-06-29T23:53:02.712162373Z app=edgex-device-rfid-llrp source=device.go:470 device=SpeedwayR-11-25-D6 msg="Device connection restored."
level=INFO ts=2021-06-29T23:53:02.712176131Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgGetSupportedVersion device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=DEBUG ts=2021-06-29T23:53:02.712213215Z app=edgex-device-rfid-llrp source=manageddevices.go:127 msg="Updating managed Device: : SpeedwayR-11-25-D6\n"
level=INFO ts=2021-06-29T23:53:02.712540401Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgErrorMessage device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:53:02.712584957Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=DEBUG ts=2021-06-29T23:53:02.712627907Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgErrorMessage device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:53:02.725483232Z app=edgex-device-rfid-llrp source=device.go:481 device=SpeedwayR-11-25-D6 msg="Setting Reader KeepAlive spec."
level=DEBUG ts=2021-06-29T23:53:02.725527439Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgSetReaderConfig msg="Attempting send."
level=INFO ts=2021-06-29T23:53:02.72556564Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgSetReaderConfig device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:53:02.726005404Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:53:02.726045141Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:53:02.726139631Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:53:02.726188447Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=06804ad1-58f3-4e21-8350-3a22df46a1ce msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:53:02.727309611Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=06804ad1-58f3-4e21-8350-3a22df46a1ce msg="SendEvent: Pushed event to core data"
level=ERROR ts=2021-06-29T23:53:02.72793989Z app=edgex-device-rfid-llrp source=command.go:64 msg="SpeedwayR-11-25-D6 is disabled; GET"
level=INFO ts=2021-06-29T23:53:02.731063073Z app=edgex-device-rfid-llrp source=device.go:119 msg="Updated device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:53:02.731127253Z app=edgex-device-rfid-llrp source=driver.go:640 msg="Updating device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] adminState: UNLOCKED"
level=DEBUG ts=2021-06-29T23:53:02.731187173Z app=edgex-device-rfid-llrp source=device.go:129 msg="Invoked driver.UpdateDevice callback for SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:53:02.731208683Z app=edgex-device-rfid-llrp source=device.go:136 msg="Handler - restarting AutoEvents for updated device SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:53:02.979551191Z app=edgex-device-rfid-llrp source=command.go:276 msg="Handler - execReadCmd: deviceResource: ReaderCapabilities"
level=DEBUG ts=2021-06-29T23:53:02.979717543Z app=edgex-device-rfid-llrp source=command.go:283 msg="Handler - execReadCmd: deviceResource: {\"description\":\"The capabilities of a reader\",\"name\":\"ReaderCapabilities\",\"properties\":{\"value\":{\"type\":\"String\",\"readWrite\":\"R\"}}}"
level=DEBUG ts=2021-06-29T23:53:02.979786822Z app=edgex-device-rfid-llrp source=driver.go:271 msg="LLRP-Driver.HandleReadCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ReaderCapabilities Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-29T23:53:02.979829911Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgGetReaderCapabilities msg="Attempting send."
level=INFO ts=2021-06-29T23:53:02.979891228Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgGetReaderCapabilities device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:53:02.980353549Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgGetReaderCapabilitiesResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:53:02.980451042Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgGetReaderCapabilitiesResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:53:02.981512914Z app=edgex-device-rfid-llrp source=command.go:227 msg="Handler - execReadCmd: device: SpeedwayR-11-25-D6 DeviceResource: ReaderCapabilities reading: {\"origin\":1625010782981323726,\"device\":\"SpeedwayR-11-25-D6\",\"name\":\"ReaderCapabilities\",\"value\":\"{\\\"LLRPStatus\\\":{\\\"Status\\\":0,\\\"ErrorDescription\\\":\\\"\\\",\\\"FieldError\\\":null,\\\"ParameterError\\\":null},\\\"GeneralDeviceCapabilities\\\":{\\\"MaxSupportedAntennas\\\":4,\\\"CanSetAntennaProperties\\\":false,\\\"HasUTCClock\\\":true,\\\"DeviceManufacturer\\\":25882,\\\"Model\\\":2001002,\\\"FirmwareVersion\\\":\\\"5.14.0.240\\\",\\\"ReceiveSensitivities\\\":[{\\\"Index\\\":1,\\\"ReceiveSensitivity\\\":0},{\\\"Index\\\":2,\\\"ReceiveSensitivity\\\":10},{\\\"Index\\\":3,\\\"ReceiveSensitivity\\\":11},{\\\"Index\\\":4,\\\"ReceiveSensitivity\\\":12},{\\\"Index\\\":5,\\\"ReceiveSensitivity\\\":13},{\\\"Index\\\":6,\\\"ReceiveSensitivity\\\":14},{\\\"Index\\\":7,\\\"ReceiveSensitivity\\\":15},{\\\"Index\\\":8,\\\"ReceiveSensitivity\\\":16},{\\\"Index\\\":9,\\\"ReceiveSensitivity\\\":17},{\\\"Index\\\":10,\\\"ReceiveSensitivity\\\":18},{\\\"Index\\\":11,\\\"ReceiveSensitivity\\\":19},{\\\"Index\\\":12,\\\"ReceiveSensitivity\\\":20},{\\\"Index\\\":13,\\\"ReceiveSensitivity\\\":21},{\\\"Index\\\":14,\\\"ReceiveSensitivity\\\":22},{\\\"Index\\\":15,\\\"ReceiveSensitivity\\\":23},{\\\"Index\\\":16,\\\"ReceiveSensitivity\\\":24},{\\\"Index\\\":17,\\\"ReceiveSensitivity\\\":25},{\\\"Index\\\":18,\\\"ReceiveSensitivity\\\":26},{\\\"Index\\\":19,\\\"ReceiveSensitivity\\\":27},{\\\"Index\\\":20,\\\"ReceiveSensitivity\\\":28},{\\\"Index\\\":21,\\\"ReceiveSensitivity\\\":29},{\\\"Index\\\":22,\\\"ReceiveSensitivity\\\":30},{\\\"Index\\\":23,\\\"ReceiveSensitivity\\\":31},{\\\"Index\\\":24,\\\"ReceiveSensitivity\\\":32},{\\\"Index\\\":25,\\\"ReceiveSensitivity\\\":33},{\\\"Index\\\":26,\\\"ReceiveSensitivity\\\":34},{\\\"Index\\\":27,\\\"ReceiveSensitivity\\\":35},{\\\"Index\\\":28,\\\"ReceiveSensitivity\\\":36},{\\\"Index\\\":29,\\\"ReceiveSensitivity\\\":37},{\\\"Index\\\":30,\\\"ReceiveSensitivity\\\":38},{\\\"Index\\\":31,\\\"ReceiveSensitivity\\\":39},{\\\"Index\\\":32,\\\"ReceiveSensitivity\\\":40},{\\\"Index\\\":33,\\\"ReceiveSensitivity\\\":41},{\\\"Index\\\":34,\\\"ReceiveSensitivity\\\":42},{\\\"Index\\\":35,\\\"ReceiveSensitivity\\\":43},{\\\"Index\\\":36,\\\"ReceiveSensitivity\\\":44},{\\\"Index\\\":37,\\\"ReceiveSensitivity\\\":45},{\\\"Index\\\":38,\\\"ReceiveSensitivity\\\":46},{\\\"Index\\\":39,\\\"ReceiveSensitivity\\\":47},{\\\"Index\\\":40,\\\"ReceiveSensitivity\\\":48},{\\\"Index\\\":41,\\\"ReceiveSensitivity\\\":49},{\\\"Index\\\":42,\\\"ReceiveSensitivity\\\":50}],\\\"PerAntennaReceiveSensitivityRanges\\\":null,\\\"GPIOCapabilities\\\":{\\\"NumGPIs\\\":4,\\\"NumGPOs\\\":4},\\\"PerAntennaAirProtocols\\\":[{\\\"AntennaID\\\":1,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":2,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":3,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":4,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"}],\\\"MaximumReceiveSensitivity\\\":null},\\\"LLRPCapabilities\\\":{\\\"CanDoRFSurvey\\\":false,\\\"CanReportBufferFillWarning\\\":true,\\\"SupportsClientRequestOpSpec\\\":false,\\\"CanDoTagInventoryStateAwareSingulation\\\":false,\\\"SupportsEventsAndReportHolding\\\":true,\\\"MaxPriorityLevelSupported\\\":1,\\\"ClientRequestedOpSpecTimeout\\\":0,\\\"MaxROSpecs\\\":1,\\\"MaxSpecsPerROSpec\\\":32,\\\"MaxInventoryParameterSpecsPerAISpec\\\":1,\\\"MaxAccessSpecs\\\":1508,\\\"MaxOpSpecsPerAccessSpec\\\":8},\\\"RegulatoryCapabilities\\\":{\\\"CountryCode\\\":840,\\\"CommunicationsStandard\\\":1,\\\"UHFBandCapabilities\\\":{\\\"TransmitPowerLevels\\\":[{\\\"Index\\\":1,\\\"TransmitPowerValue\\\":1000},{\\\"Index\\\":2,\\\"TransmitPowerValue\\\":1025},{\\\"Index\\\":3,\\\"TransmitPowerValue\\\":1050},{\\\"Index\\\":4,\\\"TransmitPowerValue\\\":1075},{\\\"Index\\\":5,\\\"TransmitPowerValue\\\":1100},{\\\"Index\\\":6,\\\"TransmitPowerValue\\\":1125},{\\\"Index\\\":7,\\\"TransmitPowerValue\\\":1150},{\\\"Index\\\":8,\\\"TransmitPowerValue\\\":1175},{\\\"Index\\\":9,\\\"TransmitPowerValue\\\":1200},{\\\"Index\\\":10,\\\"TransmitPowerValue\\\":1225},{\\\"Index\\\":11,\\\"TransmitPowerValue\\\":1250},{\\\"Index\\\":12,\\\"TransmitPowerValue\\\":1275},{\\\"Index\\\":13,\\\"TransmitPowerValue\\\":1300},{\\\"Index\\\":14,\\\"TransmitPowerValue\\\":1325},{\\\"Index\\\":15,\\\"TransmitPowerValue\\\":1350},{\\\"Index\\\":16,\\\"TransmitPowerValue\\\":1375},{\\\"Index\\\":17,\\\"TransmitPowerValue\\\":1400},{\\\"Index\\\":18,\\\"TransmitPowerValue\\\":1425},{\\\"Index\\\":19,\\\"TransmitPowerValue\\\":1450},{\\\"Index\\\":20,\\\"TransmitPowerValue\\\":1475},{\\\"Index\\\":21,\\\"TransmitPowerValue\\\":1500},{\\\"Index\\\":22,\\\"TransmitPowerValue\\\":1525},{\\\"Index\\\":23,\\\"TransmitPowerValue\\\":1550},{\\\"Index\\\":24,\\\"TransmitPowerValue\\\":1575},{\\\"Index\\\":25,\\\"TransmitPowerValue\\\":1600},{\\\"Index\\\":26,\\\"TransmitPowerValue\\\":1625},{\\\"Index\\\":27,\\\"TransmitPowerValue\\\":1650},{\\\"Index\\\":28,\\\"TransmitPowerValue\\\":1675},{\\\"Index\\\":29,\\\"TransmitPowerValue\\\":1700},{\\\"Index\\\":30,\\\"TransmitPowerValue\\\":1725},{\\\"Index\\\":31,\\\"TransmitPowerValue\\\":1750},{\\\"Index\\\":32,\\\"TransmitPowerValue\\\":1775},{\\\"Index\\\":33,\\\"TransmitPowerValue\\\":1800},{\\\"Index\\\":34,\\\"TransmitPowerValue\\\":1825},{\\\"Index\\\":35,\\\"TransmitPowerValue\\\":1850},{\\\"Index\\\":36,\\\"TransmitPowerValue\\\":1875},{\\\"Index\\\":37,\\\"TransmitPowerValue\\\":1900},{\\\"Index\\\":38,\\\"TransmitPowerValue\\\":1925},{\\\"Index\\\":39,\\\"TransmitPowerValue\\\":1950},{\\\"Index\\\":40,\\\"TransmitPowerValue\\\":1975},{\\\"Index\\\":41,\\\"TransmitPowerValue\\\":2000},{\\\"Index\\\":42,\\\"TransmitPowerValue\\\":2025},{\\\"Index\\\":43,\\\"TransmitPowerValue\\\":2050},{\\\"Index\\\":44,\\\"TransmitPowerValue\\\":2075},{\\\"Index\\\":45,\\\"TransmitPowerValue\\\":2100},{\\\"Index\\\":46,\\\"TransmitPowerValue\\\":2125},{\\\"Index\\\":47,\\\"TransmitPowerValue\\\":2150},{\\\"Index\\\":48,\\\"TransmitPowerValue\\\":2175},{\\\"Index\\\":49,\\\"TransmitPowerValue\\\":2200},{\\\"Index\\\":50,\\\"TransmitPowerValue\\\":2225},{\\\"Index\\\":51,\\\"TransmitPowerValue\\\":2250},{\\\"Index\\\":52,\\\"TransmitPowerValue\\\":2275},{\\\"Index\\\":53,\\\"TransmitPowerValue\\\":2300},{\\\"Index\\\":54,\\\"TransmitPowerValue\\\":2325},{\\\"Index\\\":55,\\\"TransmitPowerValue\\\":2350},{\\\"Index\\\":56,\\\"TransmitPowerValue\\\":2375},{\\\"Index\\\":57,\\\"TransmitPowerValue\\\":2400},{\\\"Index\\\":58,\\\"TransmitPowerValue\\\":2425},{\\\"Index\\\":59,\\\"TransmitPowerValue\\\":2450},{\\\"Index\\\":60,\\\"TransmitPowerValue\\\":2475},{\\\"Index\\\":61,\\\"TransmitPowerValue\\\":2500},{\\\"Index\\\":62,\\\"TransmitPowerValue\\\":2525},{\\\"Index\\\":63,\\\"TransmitPowerValue\\\":2550},{\\\"Index\\\":64,\\\"TransmitPowerValue\\\":2575},{\\\"Index\\\":65,\\\"TransmitPowerValue\\\":2600},{\\\"Index\\\":66,\\\"TransmitPowerValue\\\":2625},{\\\"Index\\\":67,\\\"TransmitPowerValue\\\":2650},{\\\"Index\\\":68,\\\"TransmitPowerValue\\\":2675},{\\\"Index\\\":69,\\\"TransmitPowerValue\\\":2700},{\\\"Index\\\":70,\\\"TransmitPowerValue\\\":2725},{\\\"Index\\\":71,\\\"TransmitPowerValue\\\":2750},{\\\"Index\\\":72,\\\"TransmitPowerValue\\\":2775},{\\\"Index\\\":73,\\\"TransmitPowerValue\\\":2800},{\\\"Index\\\":74,\\\"TransmitPowerValue\\\":2825},{\\\"Index\\\":75,\\\"TransmitPowerValue\\\":2850},{\\\"Index\\\":76,\\\"TransmitPowerValue\\\":2875},{\\\"Index\\\":77,\\\"TransmitPowerValue\\\":2900},{\\\"Index\\\":78,\\\"TransmitPowerValue\\\":2925},{\\\"Index\\\":79,\\\"TransmitPowerValue\\\":2950},{\\\"Index\\\":80,\\\"TransmitPowerValue\\\":2975},{\\\"Index\\\":81,\\\"TransmitPowerValue\\\":3000}],\\\"FrequencyInformation\\\":{\\\"Hopping\\\":true,\\\"FrequencyHopTables\\\":[{\\\"HopTableID\\\":1,\\\"Frequencies\\\":[909250,908250,925750,911250,910750,926750,917750,905250,927250,921250,925250,919250,924750,916250,919750,913250,926250,916750,918750,914250,909750,917250,908750,902750,921750,913750,915750,923750,904250,903750,903250,907750,915250,924250,912750,918250,912250,910250,922250,905750,906750,920750,923250,906250,914750,911750,920250,907250,922750,904750]}],\\\"FixedFrequencyTable\\\":null},\\\"C1G2RFModes\\\":{\\\"UHFC1G2RFModeTableEntries\\\":[{\\\"ModeID\\\":0,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":2,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":1,\\\"ForwardLinkModulation\\\":2,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":2,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":2,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":3,\\\"BackscatterDataRate\\\":274000,\\\"PIERatio\\\":2000,\\\"MinTariTime\\\":20000,\\\"MaxTariTime\\\":20000,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":3,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":3,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":3,\\\"BackscatterDataRate\\\":170600,\\\"PIERatio\\\":2000,\\\"MinTariTime\\\":20000,\\\"MaxTariTime\\\":20000,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":4,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":2,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":7140,\\\"MaxTariTime\\\":7140,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1000,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1002,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1003,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1004,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1005,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0}]},\\\"RFSurveyFrequencyCapabilities\\\":null},\\\"Custom\\\":null},\\\"C1G2LLRPCapabilities\\\":{\\\"SupportsBlockErase\\\":false,\\\"SupportsBlockWrite\\\":true,\\\"SupportsBlockPermalock\\\":false,\\\"SupportsTagRecommissioning\\\":false,\\\"SupportsUMIMethod2\\\":false,\\\"SupportsXPC\\\":false,\\\"MaxSelectFiltersPerQuery\\\":2},\\\"Custom\\\":null}\",\"valueType\":\"String\"}"
level=DEBUG ts=2021-06-29T23:53:02.98234195Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=8dbdabee-ef59-44b6-95f0-8a822fe2ab02 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:53:02.983200317Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ImpinjCustomExtensionMessage in the request parameters"
level=DEBUG ts=2021-06-29T23:53:02.983227833Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ImpinjCustomExtensionMessage"
level=DEBUG ts=2021-06-29T23:53:02.983243407Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ImpinjCustomExtensionMessage"
level=DEBUG ts=2021-06-29T23:53:02.983275741Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ImpinjCustomExtensionMessage Attributes:map[subtype:21 vendor:25882] Type:2}]"
level=DEBUG ts=2021-06-29T23:53:02.983302978Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgCustomMessage msg="Attempting send."
level=INFO ts=2021-06-29T23:53:02.983336499Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:53:02.983496356Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:53:02.983542519Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:53:02.98379924Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ImpinjCustomExtensionMessage not found"
level=DEBUG ts=2021-06-29T23:53:02.983864188Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=9795b6ae-b71b-48e9-948f-db7716a94572 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:53:02.98466494Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ReaderConfig in the request parameters"
level=DEBUG ts=2021-06-29T23:53:02.98469462Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ReaderConfig"
level=DEBUG ts=2021-06-29T23:53:02.984712988Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ReaderConfig"
level=DEBUG ts=2021-06-29T23:53:02.984752865Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ReaderConfig Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-29T23:53:02.985341661Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=9795b6ae-b71b-48e9-948f-db7716a94572 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:53:02.985517301Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=8dbdabee-ef59-44b6-95f0-8a822fe2ab02 msg="SendEvent: Pushed event to core data"
level=INFO ts=2021-06-29T23:53:02.986283134Z app=edgex-device-rfid-llrp source=device.go:234 forcedKA=30s msg="Adding device-service-enforced a KeepAlive spec to ReaderConfig."
level=DEBUG ts=2021-06-29T23:53:02.986315329Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgSetReaderConfig msg="Attempting send."
level=INFO ts=2021-06-29T23:53:02.986367707Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgSetReaderConfig device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:53:02.986671219Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:53:02.986719336Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:53:02.986884291Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=dcb006fb-38eb-4d13-86af-d7a264b86ea8 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:53:02.987081372Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ROSpecID in the request parameters"
level=DEBUG ts=2021-06-29T23:53:02.987110563Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for Action in the request parameters"
level=DEBUG ts=2021-06-29T23:53:02.987132353Z app=edgex-device-rfid-llrp source=command.go:451 msg="there is no Action in the request parameters, retrieving value from the Parameter field from the ResourceOperation"
level=DEBUG ts=2021-06-29T23:53:02.987159659Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ROSpecID"
level=DEBUG ts=2021-06-29T23:53:02.987175023Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ROSpecID"
level=DEBUG ts=2021-06-29T23:53:02.987188641Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: Action"
level=DEBUG ts=2021-06-29T23:53:02.987201561Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: Action"
level=DEBUG ts=2021-06-29T23:53:02.987229985Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ROSpecID Attributes:map[] Type:7} {DeviceResourceName:Action Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-29T23:53:02.987267836Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgDeleteROSpec msg="Attempting send."
level=INFO ts=2021-06-29T23:53:02.987303872Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgDeleteROSpec device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:53:02.987467431Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgDeleteROSpecResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:53:02.987521066Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgDeleteROSpecResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:53:02.987669609Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ROSpecID not found"
level=DEBUG ts=2021-06-29T23:53:02.987703689Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=decbaf90-90bb-4403-b9cf-8fe8332ef377 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:53:02.987897627Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ROSpec in the request parameters"
level=DEBUG ts=2021-06-29T23:53:02.987932825Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ROSpec"
level=DEBUG ts=2021-06-29T23:53:02.98794791Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ROSpec"
level=DEBUG ts=2021-06-29T23:53:02.987988904Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ROSpec Attributes:map[] Type:2}]"
level=ERROR ts=2021-06-29T23:53:02.988396264Z app=edgex-device-rfid-llrp source=utils.go:302 msg="Failed to update last connected value for device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:53:02.988456114Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=dcb006fb-38eb-4d13-86af-d7a264b86ea8 msg="SendEvent: Pushed event to core data"
level=ERROR ts=2021-06-29T23:53:02.989133184Z app=edgex-device-rfid-llrp source=utils.go:302 msg="Failed to update last connected value for device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:53:02.989171455Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=decbaf90-90bb-4403-b9cf-8fe8332ef377 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:53:02.999754911Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgAddROSpec msg="Attempting send."
level=INFO ts=2021-06-29T23:53:02.999811269Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgAddROSpec device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:53:02.999981462Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgAddROSpecResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:53:03.000035865Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgAddROSpecResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:53:03.000166321Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=394345fd-9ab9-4be5-9367-80b8483d283a msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:53:03.00094249Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=394345fd-9ab9-4be5-9367-80b8483d283a msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:53:32.986978226Z app=edgex-device-rfid-llrp source=logging.go:32 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:53:32.987085495Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:53:32.987173141Z app=edgex-device-rfid-llrp source=logging.go:23 type=MsgKeepAliveAck device=SpeedwayR-11-25-D6 msg="Sending LLRP message"


level=INFO ts=2021-06-29T23:53:42.353719134Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:53:42.353870471Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=ERROR ts=2021-06-29T23:53:42.353996666Z app=edgex-device-rfid-llrp source=device.go:166 error="failed to get next message: failed to read header: EOF" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
level=DEBUG ts=2021-06-29T23:53:42.35411057Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
2021/06/29 16:53:42 retry attempt: 1, wait: 0s
level=DEBUG ts=2021-06-29T23:53:42.354236836Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:53:42.35423935Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=a0e1be06-981d-4780-9416-77844f8900b5 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=ERROR ts=2021-06-29T23:53:42.354553686Z app=edgex-device-rfid-llrp source=device.go:144 error="dial tcp 10.0.0.53:5084: connect: connection refused" address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Failed to dial Reader."
level=WARN ts=2021-06-29T23:53:42.354626457Z app=edgex-device-rfid-llrp source=device.go:197 device=SpeedwayR-11-25-D6 msg="Failed to connect to Device after multiple tries."
level=DEBUG ts=2021-06-29T23:53:42.354673876Z app=edgex-device-rfid-llrp source=manageddevices.go:127 msg="Updating managed Device: : SpeedwayR-11-25-D6\n"
level=DEBUG ts=2021-06-29T23:53:42.356769756Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=a0e1be06-981d-4780-9416-77844f8900b5 msg="SendEvent: Pushed event to core data"
2021/06/29 16:53:42 retry attempt: 5, wait: 2m5s
level=INFO ts=2021-06-29T23:53:42.372811328Z app=edgex-device-rfid-llrp source=device.go:119 msg="Updated device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:53:42.372894504Z app=edgex-device-rfid-llrp source=driver.go:640 msg="Updating device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] adminState: UNLOCKED"
level=DEBUG ts=2021-06-29T23:53:42.372966855Z app=edgex-device-rfid-llrp source=device.go:129 msg="Invoked driver.UpdateDevice callback for SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:53:42.372995767Z app=edgex-device-rfid-llrp source=device.go:136 msg="Handler - restarting AutoEvents for updated device SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:55:47.365264277Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-29T23:55:47.365787007Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-29T23:55:47.366206658Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:55:47.366235571Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=INFO ts=2021-06-29T23:55:47.366315604Z app=edgex-device-rfid-llrp source=device.go:470 device=SpeedwayR-11-25-D6 msg="Device connection restored."
level=DEBUG ts=2021-06-29T23:55:47.366375384Z app=edgex-device-rfid-llrp source=manageddevices.go:127 msg="Updating managed Device: : SpeedwayR-11-25-D6\n"
level=INFO ts=2021-06-29T23:55:47.366404437Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgGetSupportedVersion device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:55:47.366920672Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgErrorMessage device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-29T23:55:47.366969558Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=DEBUG ts=2021-06-29T23:55:47.367032621Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgErrorMessage device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:55:47.378125401Z app=edgex-device-rfid-llrp source=device.go:481 device=SpeedwayR-11-25-D6 msg="Setting Reader KeepAlive spec."
level=DEBUG ts=2021-06-29T23:55:47.378233439Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgSetReaderConfig msg="Attempting send."
level=INFO ts=2021-06-29T23:55:47.37831445Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgSetReaderConfig device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:55:47.378647084Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:55:47.378705468Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:55:47.378797304Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:55:47.378832641Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=b0efccb1-6b58-4290-935b-f4fd71de3d37 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:55:47.380009536Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=b0efccb1-6b58-4290-935b-f4fd71de3d37 msg="SendEvent: Pushed event to core data"
level=ERROR ts=2021-06-29T23:55:47.380683813Z app=edgex-device-rfid-llrp source=command.go:64 msg="SpeedwayR-11-25-D6 is disabled; GET"
level=INFO ts=2021-06-29T23:55:47.383573112Z app=edgex-device-rfid-llrp source=device.go:119 msg="Updated device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:55:47.383611103Z app=edgex-device-rfid-llrp source=driver.go:640 msg="Updating device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] adminState: UNLOCKED"
level=DEBUG ts=2021-06-29T23:55:47.383643019Z app=edgex-device-rfid-llrp source=device.go:129 msg="Invoked driver.UpdateDevice callback for SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:55:47.383658453Z app=edgex-device-rfid-llrp source=device.go:136 msg="Handler - restarting AutoEvents for updated device SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:55:47.631910587Z app=edgex-device-rfid-llrp source=command.go:276 msg="Handler - execReadCmd: deviceResource: ReaderCapabilities"
level=DEBUG ts=2021-06-29T23:55:47.632107318Z app=edgex-device-rfid-llrp source=command.go:283 msg="Handler - execReadCmd: deviceResource: {\"description\":\"The capabilities of a reader\",\"name\":\"ReaderCapabilities\",\"properties\":{\"value\":{\"type\":\"String\",\"readWrite\":\"R\"}}}"
level=DEBUG ts=2021-06-29T23:55:47.632183021Z app=edgex-device-rfid-llrp source=driver.go:271 msg="LLRP-Driver.HandleReadCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ReaderCapabilities Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-29T23:55:47.632252928Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgGetReaderCapabilities msg="Attempting send."
level=INFO ts=2021-06-29T23:55:47.632334358Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgGetReaderCapabilities device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:55:47.632914774Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgGetReaderCapabilitiesResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:55:47.633037827Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgGetReaderCapabilitiesResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:55:47.633211582Z app=edgex-device-rfid-llrp source=command.go:227 msg="Handler - execReadCmd: device: SpeedwayR-11-25-D6 DeviceResource: ReaderCapabilities reading: {\"origin\":1625010947633155014,\"device\":\"SpeedwayR-11-25-D6\",\"name\":\"ReaderCapabilities\",\"value\":\"{\\\"LLRPStatus\\\":{\\\"Status\\\":0,\\\"ErrorDescription\\\":\\\"\\\",\\\"FieldError\\\":null,\\\"ParameterError\\\":null},\\\"GeneralDeviceCapabilities\\\":{\\\"MaxSupportedAntennas\\\":4,\\\"CanSetAntennaProperties\\\":false,\\\"HasUTCClock\\\":true,\\\"DeviceManufacturer\\\":25882,\\\"Model\\\":2001002,\\\"FirmwareVersion\\\":\\\"5.14.0.240\\\",\\\"ReceiveSensitivities\\\":[{\\\"Index\\\":1,\\\"ReceiveSensitivity\\\":0},{\\\"Index\\\":2,\\\"ReceiveSensitivity\\\":10},{\\\"Index\\\":3,\\\"ReceiveSensitivity\\\":11},{\\\"Index\\\":4,\\\"ReceiveSensitivity\\\":12},{\\\"Index\\\":5,\\\"ReceiveSensitivity\\\":13},{\\\"Index\\\":6,\\\"ReceiveSensitivity\\\":14},{\\\"Index\\\":7,\\\"ReceiveSensitivity\\\":15},{\\\"Index\\\":8,\\\"ReceiveSensitivity\\\":16},{\\\"Index\\\":9,\\\"ReceiveSensitivity\\\":17},{\\\"Index\\\":10,\\\"ReceiveSensitivity\\\":18},{\\\"Index\\\":11,\\\"ReceiveSensitivity\\\":19},{\\\"Index\\\":12,\\\"ReceiveSensitivity\\\":20},{\\\"Index\\\":13,\\\"ReceiveSensitivity\\\":21},{\\\"Index\\\":14,\\\"ReceiveSensitivity\\\":22},{\\\"Index\\\":15,\\\"ReceiveSensitivity\\\":23},{\\\"Index\\\":16,\\\"ReceiveSensitivity\\\":24},{\\\"Index\\\":17,\\\"ReceiveSensitivity\\\":25},{\\\"Index\\\":18,\\\"ReceiveSensitivity\\\":26},{\\\"Index\\\":19,\\\"ReceiveSensitivity\\\":27},{\\\"Index\\\":20,\\\"ReceiveSensitivity\\\":28},{\\\"Index\\\":21,\\\"ReceiveSensitivity\\\":29},{\\\"Index\\\":22,\\\"ReceiveSensitivity\\\":30},{\\\"Index\\\":23,\\\"ReceiveSensitivity\\\":31},{\\\"Index\\\":24,\\\"ReceiveSensitivity\\\":32},{\\\"Index\\\":25,\\\"ReceiveSensitivity\\\":33},{\\\"Index\\\":26,\\\"ReceiveSensitivity\\\":34},{\\\"Index\\\":27,\\\"ReceiveSensitivity\\\":35},{\\\"Index\\\":28,\\\"ReceiveSensitivity\\\":36},{\\\"Index\\\":29,\\\"ReceiveSensitivity\\\":37},{\\\"Index\\\":30,\\\"ReceiveSensitivity\\\":38},{\\\"Index\\\":31,\\\"ReceiveSensitivity\\\":39},{\\\"Index\\\":32,\\\"ReceiveSensitivity\\\":40},{\\\"Index\\\":33,\\\"ReceiveSensitivity\\\":41},{\\\"Index\\\":34,\\\"ReceiveSensitivity\\\":42},{\\\"Index\\\":35,\\\"ReceiveSensitivity\\\":43},{\\\"Index\\\":36,\\\"ReceiveSensitivity\\\":44},{\\\"Index\\\":37,\\\"ReceiveSensitivity\\\":45},{\\\"Index\\\":38,\\\"ReceiveSensitivity\\\":46},{\\\"Index\\\":39,\\\"ReceiveSensitivity\\\":47},{\\\"Index\\\":40,\\\"ReceiveSensitivity\\\":48},{\\\"Index\\\":41,\\\"ReceiveSensitivity\\\":49},{\\\"Index\\\":42,\\\"ReceiveSensitivity\\\":50}],\\\"PerAntennaReceiveSensitivityRanges\\\":null,\\\"GPIOCapabilities\\\":{\\\"NumGPIs\\\":4,\\\"NumGPOs\\\":4},\\\"PerAntennaAirProtocols\\\":[{\\\"AntennaID\\\":1,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":2,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":3,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":4,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"}],\\\"MaximumReceiveSensitivity\\\":null},\\\"LLRPCapabilities\\\":{\\\"CanDoRFSurvey\\\":false,\\\"CanReportBufferFillWarning\\\":true,\\\"SupportsClientRequestOpSpec\\\":false,\\\"CanDoTagInventoryStateAwareSingulation\\\":false,\\\"SupportsEventsAndReportHolding\\\":true,\\\"MaxPriorityLevelSupported\\\":1,\\\"ClientRequestedOpSpecTimeout\\\":0,\\\"MaxROSpecs\\\":1,\\\"MaxSpecsPerROSpec\\\":32,\\\"MaxInventoryParameterSpecsPerAISpec\\\":1,\\\"MaxAccessSpecs\\\":1508,\\\"MaxOpSpecsPerAccessSpec\\\":8},\\\"RegulatoryCapabilities\\\":{\\\"CountryCode\\\":840,\\\"CommunicationsStandard\\\":1,\\\"UHFBandCapabilities\\\":{\\\"TransmitPowerLevels\\\":[{\\\"Index\\\":1,\\\"TransmitPowerValue\\\":1000},{\\\"Index\\\":2,\\\"TransmitPowerValue\\\":1025},{\\\"Index\\\":3,\\\"TransmitPowerValue\\\":1050},{\\\"Index\\\":4,\\\"TransmitPowerValue\\\":1075},{\\\"Index\\\":5,\\\"TransmitPowerValue\\\":1100},{\\\"Index\\\":6,\\\"TransmitPowerValue\\\":1125},{\\\"Index\\\":7,\\\"TransmitPowerValue\\\":1150},{\\\"Index\\\":8,\\\"TransmitPowerValue\\\":1175},{\\\"Index\\\":9,\\\"TransmitPowerValue\\\":1200},{\\\"Index\\\":10,\\\"TransmitPowerValue\\\":1225},{\\\"Index\\\":11,\\\"TransmitPowerValue\\\":1250},{\\\"Index\\\":12,\\\"TransmitPowerValue\\\":1275},{\\\"Index\\\":13,\\\"TransmitPowerValue\\\":1300},{\\\"Index\\\":14,\\\"TransmitPowerValue\\\":1325},{\\\"Index\\\":15,\\\"TransmitPowerValue\\\":1350},{\\\"Index\\\":16,\\\"TransmitPowerValue\\\":1375},{\\\"Index\\\":17,\\\"TransmitPowerValue\\\":1400},{\\\"Index\\\":18,\\\"TransmitPowerValue\\\":1425},{\\\"Index\\\":19,\\\"TransmitPowerValue\\\":1450},{\\\"Index\\\":20,\\\"TransmitPowerValue\\\":1475},{\\\"Index\\\":21,\\\"TransmitPowerValue\\\":1500},{\\\"Index\\\":22,\\\"TransmitPowerValue\\\":1525},{\\\"Index\\\":23,\\\"TransmitPowerValue\\\":1550},{\\\"Index\\\":24,\\\"TransmitPowerValue\\\":1575},{\\\"Index\\\":25,\\\"TransmitPowerValue\\\":1600},{\\\"Index\\\":26,\\\"TransmitPowerValue\\\":1625},{\\\"Index\\\":27,\\\"TransmitPowerValue\\\":1650},{\\\"Index\\\":28,\\\"TransmitPowerValue\\\":1675},{\\\"Index\\\":29,\\\"TransmitPowerValue\\\":1700},{\\\"Index\\\":30,\\\"TransmitPowerValue\\\":1725},{\\\"Index\\\":31,\\\"TransmitPowerValue\\\":1750},{\\\"Index\\\":32,\\\"TransmitPowerValue\\\":1775},{\\\"Index\\\":33,\\\"TransmitPowerValue\\\":1800},{\\\"Index\\\":34,\\\"TransmitPowerValue\\\":1825},{\\\"Index\\\":35,\\\"TransmitPowerValue\\\":1850},{\\\"Index\\\":36,\\\"TransmitPowerValue\\\":1875},{\\\"Index\\\":37,\\\"TransmitPowerValue\\\":1900},{\\\"Index\\\":38,\\\"TransmitPowerValue\\\":1925},{\\\"Index\\\":39,\\\"TransmitPowerValue\\\":1950},{\\\"Index\\\":40,\\\"TransmitPowerValue\\\":1975},{\\\"Index\\\":41,\\\"TransmitPowerValue\\\":2000},{\\\"Index\\\":42,\\\"TransmitPowerValue\\\":2025},{\\\"Index\\\":43,\\\"TransmitPowerValue\\\":2050},{\\\"Index\\\":44,\\\"TransmitPowerValue\\\":2075},{\\\"Index\\\":45,\\\"TransmitPowerValue\\\":2100},{\\\"Index\\\":46,\\\"TransmitPowerValue\\\":2125},{\\\"Index\\\":47,\\\"TransmitPowerValue\\\":2150},{\\\"Index\\\":48,\\\"TransmitPowerValue\\\":2175},{\\\"Index\\\":49,\\\"TransmitPowerValue\\\":2200},{\\\"Index\\\":50,\\\"TransmitPowerValue\\\":2225},{\\\"Index\\\":51,\\\"TransmitPowerValue\\\":2250},{\\\"Index\\\":52,\\\"TransmitPowerValue\\\":2275},{\\\"Index\\\":53,\\\"TransmitPowerValue\\\":2300},{\\\"Index\\\":54,\\\"TransmitPowerValue\\\":2325},{\\\"Index\\\":55,\\\"TransmitPowerValue\\\":2350},{\\\"Index\\\":56,\\\"TransmitPowerValue\\\":2375},{\\\"Index\\\":57,\\\"TransmitPowerValue\\\":2400},{\\\"Index\\\":58,\\\"TransmitPowerValue\\\":2425},{\\\"Index\\\":59,\\\"TransmitPowerValue\\\":2450},{\\\"Index\\\":60,\\\"TransmitPowerValue\\\":2475},{\\\"Index\\\":61,\\\"TransmitPowerValue\\\":2500},{\\\"Index\\\":62,\\\"TransmitPowerValue\\\":2525},{\\\"Index\\\":63,\\\"TransmitPowerValue\\\":2550},{\\\"Index\\\":64,\\\"TransmitPowerValue\\\":2575},{\\\"Index\\\":65,\\\"TransmitPowerValue\\\":2600},{\\\"Index\\\":66,\\\"TransmitPowerValue\\\":2625},{\\\"Index\\\":67,\\\"TransmitPowerValue\\\":2650},{\\\"Index\\\":68,\\\"TransmitPowerValue\\\":2675},{\\\"Index\\\":69,\\\"TransmitPowerValue\\\":2700},{\\\"Index\\\":70,\\\"TransmitPowerValue\\\":2725},{\\\"Index\\\":71,\\\"TransmitPowerValue\\\":2750},{\\\"Index\\\":72,\\\"TransmitPowerValue\\\":2775},{\\\"Index\\\":73,\\\"TransmitPowerValue\\\":2800},{\\\"Index\\\":74,\\\"TransmitPowerValue\\\":2825},{\\\"Index\\\":75,\\\"TransmitPowerValue\\\":2850},{\\\"Index\\\":76,\\\"TransmitPowerValue\\\":2875},{\\\"Index\\\":77,\\\"TransmitPowerValue\\\":2900},{\\\"Index\\\":78,\\\"TransmitPowerValue\\\":2925},{\\\"Index\\\":79,\\\"TransmitPowerValue\\\":2950},{\\\"Index\\\":80,\\\"TransmitPowerValue\\\":2975},{\\\"Index\\\":81,\\\"TransmitPowerValue\\\":3000}],\\\"FrequencyInformation\\\":{\\\"Hopping\\\":true,\\\"FrequencyHopTables\\\":[{\\\"HopTableID\\\":1,\\\"Frequencies\\\":[909250,908250,925750,911250,910750,926750,917750,905250,927250,921250,925250,919250,924750,916250,919750,913250,926250,916750,918750,914250,909750,917250,908750,902750,921750,913750,915750,923750,904250,903750,903250,907750,915250,924250,912750,918250,912250,910250,922250,905750,906750,920750,923250,906250,914750,911750,920250,907250,922750,904750]}],\\\"FixedFrequencyTable\\\":null},\\\"C1G2RFModes\\\":{\\\"UHFC1G2RFModeTableEntries\\\":[{\\\"ModeID\\\":0,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":2,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":1,\\\"ForwardLinkModulation\\\":2,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":2,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":2,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":3,\\\"BackscatterDataRate\\\":274000,\\\"PIERatio\\\":2000,\\\"MinTariTime\\\":20000,\\\"MaxTariTime\\\":20000,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":3,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":3,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":3,\\\"BackscatterDataRate\\\":170600,\\\"PIERatio\\\":2000,\\\"MinTariTime\\\":20000,\\\"MaxTariTime\\\":20000,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":4,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":2,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":7140,\\\"MaxTariTime\\\":7140,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1000,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1002,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1003,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1004,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1005,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0}]},\\\"RFSurveyFrequencyCapabilities\\\":null},\\\"Custom\\\":null},\\\"C1G2LLRPCapabilities\\\":{\\\"SupportsBlockErase\\\":false,\\\"SupportsBlockWrite\\\":true,\\\"SupportsBlockPermalock\\\":false,\\\"SupportsTagRecommissioning\\\":false,\\\"SupportsUMIMethod2\\\":false,\\\"SupportsXPC\\\":false,\\\"MaxSelectFiltersPerQuery\\\":2},\\\"Custom\\\":null}\",\"valueType\":\"String\"}"
level=DEBUG ts=2021-06-29T23:55:47.633868818Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=c57a61a8-4c93-4381-a449-7d63cfe51ef9 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:55:47.634615097Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ImpinjCustomExtensionMessage in the request parameters"
level=DEBUG ts=2021-06-29T23:55:47.634655393Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ImpinjCustomExtensionMessage"
level=DEBUG ts=2021-06-29T23:55:47.634677043Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ImpinjCustomExtensionMessage"
level=DEBUG ts=2021-06-29T23:55:47.634719713Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ImpinjCustomExtensionMessage Attributes:map[subtype:21 vendor:25882] Type:2}]"
level=DEBUG ts=2021-06-29T23:55:47.634760149Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgCustomMessage msg="Attempting send."
level=INFO ts=2021-06-29T23:55:47.634802121Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:55:47.634963235Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:55:47.635000528Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:55:47.6351196Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ImpinjCustomExtensionMessage not found"
level=DEBUG ts=2021-06-29T23:55:47.635158569Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=78005189-0b7d-4940-b9ca-9923f0133294 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:55:47.635312211Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ReaderConfig in the request parameters"
level=DEBUG ts=2021-06-29T23:55:47.63535132Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ReaderConfig"
level=DEBUG ts=2021-06-29T23:55:47.635378067Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ReaderConfig"
level=DEBUG ts=2021-06-29T23:55:47.63539406Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=c57a61a8-4c93-4381-a449-7d63cfe51ef9 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:55:47.635417455Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ReaderConfig Attributes:map[] Type:2}]"
level=INFO ts=2021-06-29T23:55:47.635487781Z app=edgex-device-rfid-llrp source=device.go:234 forcedKA=30s msg="Adding device-service-enforced a KeepAlive spec to ReaderConfig."
level=DEBUG ts=2021-06-29T23:55:47.635515437Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgSetReaderConfig msg="Attempting send."
level=INFO ts=2021-06-29T23:55:47.63555252Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgSetReaderConfig device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:55:47.635756724Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:55:47.635813152Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:55:47.63591707Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=0db7a7bd-8f4e-435a-9cd5-994c71ef9854 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:55:47.636204659Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=78005189-0b7d-4940-b9ca-9923f0133294 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:55:47.636227356Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ROSpecID in the request parameters"
level=DEBUG ts=2021-06-29T23:55:47.636257595Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for Action in the request parameters"
level=DEBUG ts=2021-06-29T23:55:47.636303827Z app=edgex-device-rfid-llrp source=command.go:451 msg="there is no Action in the request parameters, retrieving value from the Parameter field from the ResourceOperation"
level=DEBUG ts=2021-06-29T23:55:47.636338187Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ROSpecID"
level=DEBUG ts=2021-06-29T23:55:47.636359278Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ROSpecID"
level=DEBUG ts=2021-06-29T23:55:47.636394266Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: Action"
level=DEBUG ts=2021-06-29T23:55:47.636415986Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: Action"
level=DEBUG ts=2021-06-29T23:55:47.636453837Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ROSpecID Attributes:map[] Type:7} {DeviceResourceName:Action Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-29T23:55:47.63648715Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgDeleteROSpec msg="Attempting send."
level=INFO ts=2021-06-29T23:55:47.636528284Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgDeleteROSpec device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:55:47.636748131Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgDeleteROSpecResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:55:47.636795131Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgDeleteROSpecResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:55:47.636940602Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ROSpecID not found"
level=DEBUG ts=2021-06-29T23:55:47.637019168Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=e1a12e40-9a21-41f4-892c-9ab1660b70e4 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:55:47.637312205Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ROSpec in the request parameters"
level=DEBUG ts=2021-06-29T23:55:47.637337276Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ROSpec"
level=DEBUG ts=2021-06-29T23:55:47.637347961Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ROSpec"
level=DEBUG ts=2021-06-29T23:55:47.63738288Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ROSpec Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-29T23:55:47.637505095Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgAddROSpec msg="Attempting send."
level=DEBUG ts=2021-06-29T23:55:47.638427503Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=e1a12e40-9a21-41f4-892c-9ab1660b70e4 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:55:47.638459768Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=0db7a7bd-8f4e-435a-9cd5-994c71ef9854 msg="SendEvent: Pushed event to core data"
level=ERROR ts=2021-06-29T23:55:47.638728291Z app=edgex-device-rfid-llrp source=utils.go:302 msg="Failed to update last connected value for device: SpeedwayR-11-25-D6"
level=ERROR ts=2021-06-29T23:55:47.638852671Z app=edgex-device-rfid-llrp source=utils.go:302 msg="Failed to update last connected value for device: SpeedwayR-11-25-D6"
level=INFO ts=2021-06-29T23:55:47.662960357Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgAddROSpec device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:55:47.663154644Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgAddROSpecResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:55:47.663199619Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgAddROSpecResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:55:47.663327211Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=1fa42445-ecbe-4b21-875d-5e86f0308043 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-29T23:55:47.664134458Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=1fa42445-ecbe-4b21-875d-5e86f0308043 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-29T23:56:17.636107061Z app=edgex-device-rfid-llrp source=logging.go:32 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:56:17.636207347Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-29T23:56:17.636360221Z app=edgex-device-rfid-llrp source=logging.go:23 type=MsgKeepAliveAck device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-29T23:56:45.719701953Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-29T23:56:45.719853849Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=ERROR ts=2021-06-29T23:56:45.720013566Z app=edgex-device-rfid-llrp source=device.go:166 error="failed to get next message: failed to read header: EOF" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
level=DEBUG ts=2021-06-29T23:56:45.720074604Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-29T23:56:45.72013201Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=76acfd66-4352-43bb-aabd-47a47821cd97 msg="SendEvent: EventClient.MarshalEvent encoded event"
2021/06/29 16:56:45 retry attempt: 1, wait: 0s
level=DEBUG ts=2021-06-29T23:56:45.720256459Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=ERROR ts=2021-06-29T23:56:45.720555502Z app=edgex-device-rfid-llrp source=device.go:144 error="dial tcp 10.0.0.53:5084: connect: connection refused" address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Failed to dial Reader."
level=WARN ts=2021-06-29T23:56:45.72062464Z app=edgex-device-rfid-llrp source=device.go:197 device=SpeedwayR-11-25-D6 msg="Failed to connect to Device after multiple tries."
level=DEBUG ts=2021-06-29T23:56:45.720677786Z app=edgex-device-rfid-llrp source=manageddevices.go:127 msg="Updating managed Device: : SpeedwayR-11-25-D6\n"
level=DEBUG ts=2021-06-29T23:56:45.722130118Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=76acfd66-4352-43bb-aabd-47a47821cd97 msg="SendEvent: Pushed event to core data"
2021/06/29 16:56:45 retry attempt: 6, wait: 3m15s
level=INFO ts=2021-06-29T23:56:45.736301457Z app=edgex-device-rfid-llrp source=device.go:119 msg="Updated device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:56:45.736342591Z app=edgex-device-rfid-llrp source=driver.go:640 msg="Updating device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] adminState: UNLOCKED"
level=DEBUG ts=2021-06-29T23:56:45.736370736Z app=edgex-device-rfid-llrp source=device.go:129 msg="Invoked driver.UpdateDevice callback for SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-29T23:56:45.736384563Z app=edgex-device-rfid-llrp source=device.go:136 msg="Handler - restarting AutoEvents for updated device SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-30T00:00:00.731870507Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=DEBUG ts=2021-06-30T00:00:00.7324093Z app=edgex-device-rfid-llrp source=device.go:151 device=SpeedwayR-11-25-D6 msg="Attempting LLRP Client connection."
level=INFO ts=2021-06-30T00:00:00.733273883Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-30T00:00:00.733323467Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=INFO ts=2021-06-30T00:00:00.733456577Z app=edgex-device-rfid-llrp source=device.go:470 device=SpeedwayR-11-25-D6 msg="Device connection restored."
level=INFO ts=2021-06-30T00:00:00.733472081Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgGetSupportedVersion device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=DEBUG ts=2021-06-30T00:00:00.733535772Z app=edgex-device-rfid-llrp source=manageddevices.go:127 msg="Updating managed Device: : SpeedwayR-11-25-D6\n"
level=INFO ts=2021-06-30T00:00:00.733814282Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgErrorMessage device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=WARN ts=2021-06-30T00:00:00.733842916Z app=edgex-device-rfid-llrp source=logging.go:38 message-version=Version1_0_1 client-version=Version1_1 msg="LLRP incoming message version mismatch"
level=DEBUG ts=2021-06-30T00:00:00.733877415Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgErrorMessage device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:00:00.751675257Z app=edgex-device-rfid-llrp source=device.go:481 device=SpeedwayR-11-25-D6 msg="Setting Reader KeepAlive spec."
level=DEBUG ts=2021-06-30T00:00:00.75173392Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgSetReaderConfig msg="Attempting send."
level=INFO ts=2021-06-30T00:00:00.751788812Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgSetReaderConfig device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-30T00:00:00.751975277Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:00:00.752026747Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:00:00.752092604Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
level=DEBUG ts=2021-06-30T00:00:00.752144353Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=7454032e-9534-457b-945f-f3c99bea0df4 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-30T00:00:00.753502475Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=7454032e-9534-457b-945f-f3c99bea0df4 msg="SendEvent: Pushed event to core data"
level=ERROR ts=2021-06-30T00:00:00.754235136Z app=edgex-device-rfid-llrp source=command.go:64 msg="SpeedwayR-11-25-D6 is disabled; GET"
level=INFO ts=2021-06-30T00:00:00.759123522Z app=edgex-device-rfid-llrp source=device.go:119 msg="Updated device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-30T00:00:00.759176738Z app=edgex-device-rfid-llrp source=driver.go:640 msg="Updating device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] adminState: UNLOCKED"
level=DEBUG ts=2021-06-30T00:00:00.759239312Z app=edgex-device-rfid-llrp source=device.go:129 msg="Invoked driver.UpdateDevice callback for SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-30T00:00:00.75927046Z app=edgex-device-rfid-llrp source=device.go:136 msg="Handler - restarting AutoEvents for updated device SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-30T00:00:01.005560447Z app=edgex-device-rfid-llrp source=command.go:276 msg="Handler - execReadCmd: deviceResource: ReaderCapabilities"
level=DEBUG ts=2021-06-30T00:00:01.005808718Z app=edgex-device-rfid-llrp source=command.go:283 msg="Handler - execReadCmd: deviceResource: {\"description\":\"The capabilities of a reader\",\"name\":\"ReaderCapabilities\",\"properties\":{\"value\":{\"type\":\"String\",\"readWrite\":\"R\"}}}"
level=DEBUG ts=2021-06-30T00:00:01.005878416Z app=edgex-device-rfid-llrp source=driver.go:271 msg="LLRP-Driver.HandleReadCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ReaderCapabilities Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-30T00:00:01.005919619Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgGetReaderCapabilities msg="Attempting send."
level=INFO ts=2021-06-30T00:00:01.005976886Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgGetReaderCapabilities device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-30T00:00:01.006320694Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgGetReaderCapabilitiesResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:00:01.0063781Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgGetReaderCapabilitiesResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:00:01.00672526Z app=edgex-device-rfid-llrp source=command.go:227 msg="Handler - execReadCmd: device: SpeedwayR-11-25-D6 DeviceResource: ReaderCapabilities reading: {\"origin\":1625011201006586284,\"device\":\"SpeedwayR-11-25-D6\",\"name\":\"ReaderCapabilities\",\"value\":\"{\\\"LLRPStatus\\\":{\\\"Status\\\":0,\\\"ErrorDescription\\\":\\\"\\\",\\\"FieldError\\\":null,\\\"ParameterError\\\":null},\\\"GeneralDeviceCapabilities\\\":{\\\"MaxSupportedAntennas\\\":4,\\\"CanSetAntennaProperties\\\":false,\\\"HasUTCClock\\\":true,\\\"DeviceManufacturer\\\":25882,\\\"Model\\\":2001002,\\\"FirmwareVersion\\\":\\\"5.14.0.240\\\",\\\"ReceiveSensitivities\\\":[{\\\"Index\\\":1,\\\"ReceiveSensitivity\\\":0},{\\\"Index\\\":2,\\\"ReceiveSensitivity\\\":10},{\\\"Index\\\":3,\\\"ReceiveSensitivity\\\":11},{\\\"Index\\\":4,\\\"ReceiveSensitivity\\\":12},{\\\"Index\\\":5,\\\"ReceiveSensitivity\\\":13},{\\\"Index\\\":6,\\\"ReceiveSensitivity\\\":14},{\\\"Index\\\":7,\\\"ReceiveSensitivity\\\":15},{\\\"Index\\\":8,\\\"ReceiveSensitivity\\\":16},{\\\"Index\\\":9,\\\"ReceiveSensitivity\\\":17},{\\\"Index\\\":10,\\\"ReceiveSensitivity\\\":18},{\\\"Index\\\":11,\\\"ReceiveSensitivity\\\":19},{\\\"Index\\\":12,\\\"ReceiveSensitivity\\\":20},{\\\"Index\\\":13,\\\"ReceiveSensitivity\\\":21},{\\\"Index\\\":14,\\\"ReceiveSensitivity\\\":22},{\\\"Index\\\":15,\\\"ReceiveSensitivity\\\":23},{\\\"Index\\\":16,\\\"ReceiveSensitivity\\\":24},{\\\"Index\\\":17,\\\"ReceiveSensitivity\\\":25},{\\\"Index\\\":18,\\\"ReceiveSensitivity\\\":26},{\\\"Index\\\":19,\\\"ReceiveSensitivity\\\":27},{\\\"Index\\\":20,\\\"ReceiveSensitivity\\\":28},{\\\"Index\\\":21,\\\"ReceiveSensitivity\\\":29},{\\\"Index\\\":22,\\\"ReceiveSensitivity\\\":30},{\\\"Index\\\":23,\\\"ReceiveSensitivity\\\":31},{\\\"Index\\\":24,\\\"ReceiveSensitivity\\\":32},{\\\"Index\\\":25,\\\"ReceiveSensitivity\\\":33},{\\\"Index\\\":26,\\\"ReceiveSensitivity\\\":34},{\\\"Index\\\":27,\\\"ReceiveSensitivity\\\":35},{\\\"Index\\\":28,\\\"ReceiveSensitivity\\\":36},{\\\"Index\\\":29,\\\"ReceiveSensitivity\\\":37},{\\\"Index\\\":30,\\\"ReceiveSensitivity\\\":38},{\\\"Index\\\":31,\\\"ReceiveSensitivity\\\":39},{\\\"Index\\\":32,\\\"ReceiveSensitivity\\\":40},{\\\"Index\\\":33,\\\"ReceiveSensitivity\\\":41},{\\\"Index\\\":34,\\\"ReceiveSensitivity\\\":42},{\\\"Index\\\":35,\\\"ReceiveSensitivity\\\":43},{\\\"Index\\\":36,\\\"ReceiveSensitivity\\\":44},{\\\"Index\\\":37,\\\"ReceiveSensitivity\\\":45},{\\\"Index\\\":38,\\\"ReceiveSensitivity\\\":46},{\\\"Index\\\":39,\\\"ReceiveSensitivity\\\":47},{\\\"Index\\\":40,\\\"ReceiveSensitivity\\\":48},{\\\"Index\\\":41,\\\"ReceiveSensitivity\\\":49},{\\\"Index\\\":42,\\\"ReceiveSensitivity\\\":50}],\\\"PerAntennaReceiveSensitivityRanges\\\":null,\\\"GPIOCapabilities\\\":{\\\"NumGPIs\\\":4,\\\"NumGPOs\\\":4},\\\"PerAntennaAirProtocols\\\":[{\\\"AntennaID\\\":1,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":2,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":3,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"},{\\\"AntennaID\\\":4,\\\"AirProtocolIDs\\\":\\\"AQ==\\\"}],\\\"MaximumReceiveSensitivity\\\":null},\\\"LLRPCapabilities\\\":{\\\"CanDoRFSurvey\\\":false,\\\"CanReportBufferFillWarning\\\":true,\\\"SupportsClientRequestOpSpec\\\":false,\\\"CanDoTagInventoryStateAwareSingulation\\\":false,\\\"SupportsEventsAndReportHolding\\\":true,\\\"MaxPriorityLevelSupported\\\":1,\\\"ClientRequestedOpSpecTimeout\\\":0,\\\"MaxROSpecs\\\":1,\\\"MaxSpecsPerROSpec\\\":32,\\\"MaxInventoryParameterSpecsPerAISpec\\\":1,\\\"MaxAccessSpecs\\\":1508,\\\"MaxOpSpecsPerAccessSpec\\\":8},\\\"RegulatoryCapabilities\\\":{\\\"CountryCode\\\":840,\\\"CommunicationsStandard\\\":1,\\\"UHFBandCapabilities\\\":{\\\"TransmitPowerLevels\\\":[{\\\"Index\\\":1,\\\"TransmitPowerValue\\\":1000},{\\\"Index\\\":2,\\\"TransmitPowerValue\\\":1025},{\\\"Index\\\":3,\\\"TransmitPowerValue\\\":1050},{\\\"Index\\\":4,\\\"TransmitPowerValue\\\":1075},{\\\"Index\\\":5,\\\"TransmitPowerValue\\\":1100},{\\\"Index\\\":6,\\\"TransmitPowerValue\\\":1125},{\\\"Index\\\":7,\\\"TransmitPowerValue\\\":1150},{\\\"Index\\\":8,\\\"TransmitPowerValue\\\":1175},{\\\"Index\\\":9,\\\"TransmitPowerValue\\\":1200},{\\\"Index\\\":10,\\\"TransmitPowerValue\\\":1225},{\\\"Index\\\":11,\\\"TransmitPowerValue\\\":1250},{\\\"Index\\\":12,\\\"TransmitPowerValue\\\":1275},{\\\"Index\\\":13,\\\"TransmitPowerValue\\\":1300},{\\\"Index\\\":14,\\\"TransmitPowerValue\\\":1325},{\\\"Index\\\":15,\\\"TransmitPowerValue\\\":1350},{\\\"Index\\\":16,\\\"TransmitPowerValue\\\":1375},{\\\"Index\\\":17,\\\"TransmitPowerValue\\\":1400},{\\\"Index\\\":18,\\\"TransmitPowerValue\\\":1425},{\\\"Index\\\":19,\\\"TransmitPowerValue\\\":1450},{\\\"Index\\\":20,\\\"TransmitPowerValue\\\":1475},{\\\"Index\\\":21,\\\"TransmitPowerValue\\\":1500},{\\\"Index\\\":22,\\\"TransmitPowerValue\\\":1525},{\\\"Index\\\":23,\\\"TransmitPowerValue\\\":1550},{\\\"Index\\\":24,\\\"TransmitPowerValue\\\":1575},{\\\"Index\\\":25,\\\"TransmitPowerValue\\\":1600},{\\\"Index\\\":26,\\\"TransmitPowerValue\\\":1625},{\\\"Index\\\":27,\\\"TransmitPowerValue\\\":1650},{\\\"Index\\\":28,\\\"TransmitPowerValue\\\":1675},{\\\"Index\\\":29,\\\"TransmitPowerValue\\\":1700},{\\\"Index\\\":30,\\\"TransmitPowerValue\\\":1725},{\\\"Index\\\":31,\\\"TransmitPowerValue\\\":1750},{\\\"Index\\\":32,\\\"TransmitPowerValue\\\":1775},{\\\"Index\\\":33,\\\"TransmitPowerValue\\\":1800},{\\\"Index\\\":34,\\\"TransmitPowerValue\\\":1825},{\\\"Index\\\":35,\\\"TransmitPowerValue\\\":1850},{\\\"Index\\\":36,\\\"TransmitPowerValue\\\":1875},{\\\"Index\\\":37,\\\"TransmitPowerValue\\\":1900},{\\\"Index\\\":38,\\\"TransmitPowerValue\\\":1925},{\\\"Index\\\":39,\\\"TransmitPowerValue\\\":1950},{\\\"Index\\\":40,\\\"TransmitPowerValue\\\":1975},{\\\"Index\\\":41,\\\"TransmitPowerValue\\\":2000},{\\\"Index\\\":42,\\\"TransmitPowerValue\\\":2025},{\\\"Index\\\":43,\\\"TransmitPowerValue\\\":2050},{\\\"Index\\\":44,\\\"TransmitPowerValue\\\":2075},{\\\"Index\\\":45,\\\"TransmitPowerValue\\\":2100},{\\\"Index\\\":46,\\\"TransmitPowerValue\\\":2125},{\\\"Index\\\":47,\\\"TransmitPowerValue\\\":2150},{\\\"Index\\\":48,\\\"TransmitPowerValue\\\":2175},{\\\"Index\\\":49,\\\"TransmitPowerValue\\\":2200},{\\\"Index\\\":50,\\\"TransmitPowerValue\\\":2225},{\\\"Index\\\":51,\\\"TransmitPowerValue\\\":2250},{\\\"Index\\\":52,\\\"TransmitPowerValue\\\":2275},{\\\"Index\\\":53,\\\"TransmitPowerValue\\\":2300},{\\\"Index\\\":54,\\\"TransmitPowerValue\\\":2325},{\\\"Index\\\":55,\\\"TransmitPowerValue\\\":2350},{\\\"Index\\\":56,\\\"TransmitPowerValue\\\":2375},{\\\"Index\\\":57,\\\"TransmitPowerValue\\\":2400},{\\\"Index\\\":58,\\\"TransmitPowerValue\\\":2425},{\\\"Index\\\":59,\\\"TransmitPowerValue\\\":2450},{\\\"Index\\\":60,\\\"TransmitPowerValue\\\":2475},{\\\"Index\\\":61,\\\"TransmitPowerValue\\\":2500},{\\\"Index\\\":62,\\\"TransmitPowerValue\\\":2525},{\\\"Index\\\":63,\\\"TransmitPowerValue\\\":2550},{\\\"Index\\\":64,\\\"TransmitPowerValue\\\":2575},{\\\"Index\\\":65,\\\"TransmitPowerValue\\\":2600},{\\\"Index\\\":66,\\\"TransmitPowerValue\\\":2625},{\\\"Index\\\":67,\\\"TransmitPowerValue\\\":2650},{\\\"Index\\\":68,\\\"TransmitPowerValue\\\":2675},{\\\"Index\\\":69,\\\"TransmitPowerValue\\\":2700},{\\\"Index\\\":70,\\\"TransmitPowerValue\\\":2725},{\\\"Index\\\":71,\\\"TransmitPowerValue\\\":2750},{\\\"Index\\\":72,\\\"TransmitPowerValue\\\":2775},{\\\"Index\\\":73,\\\"TransmitPowerValue\\\":2800},{\\\"Index\\\":74,\\\"TransmitPowerValue\\\":2825},{\\\"Index\\\":75,\\\"TransmitPowerValue\\\":2850},{\\\"Index\\\":76,\\\"TransmitPowerValue\\\":2875},{\\\"Index\\\":77,\\\"TransmitPowerValue\\\":2900},{\\\"Index\\\":78,\\\"TransmitPowerValue\\\":2925},{\\\"Index\\\":79,\\\"TransmitPowerValue\\\":2950},{\\\"Index\\\":80,\\\"TransmitPowerValue\\\":2975},{\\\"Index\\\":81,\\\"TransmitPowerValue\\\":3000}],\\\"FrequencyInformation\\\":{\\\"Hopping\\\":true,\\\"FrequencyHopTables\\\":[{\\\"HopTableID\\\":1,\\\"Frequencies\\\":[909250,908250,925750,911250,910750,926750,917750,905250,927250,921250,925250,919250,924750,916250,919750,913250,926250,916750,918750,914250,909750,917250,908750,902750,921750,913750,915750,923750,904250,903750,903250,907750,915250,924250,912750,918250,912250,910250,922250,905750,906750,920750,923250,906250,914750,911750,920250,907250,922750,904750]}],\\\"FixedFrequencyTable\\\":null},\\\"C1G2RFModes\\\":{\\\"UHFC1G2RFModeTableEntries\\\":[{\\\"ModeID\\\":0,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":2,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":1,\\\"ForwardLinkModulation\\\":2,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":2,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":2,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":3,\\\"BackscatterDataRate\\\":274000,\\\"PIERatio\\\":2000,\\\"MinTariTime\\\":20000,\\\"MaxTariTime\\\":20000,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":3,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":3,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":3,\\\"BackscatterDataRate\\\":170600,\\\"PIERatio\\\":2000,\\\"MinTariTime\\\":20000,\\\"MaxTariTime\\\":20000,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":4,\\\"DivideRatio\\\":1,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":2,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":2,\\\"BackscatterDataRate\\\":640000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":7140,\\\"MaxTariTime\\\":7140,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1000,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1002,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1003,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1004,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0},{\\\"ModeID\\\":1005,\\\"DivideRatio\\\":0,\\\"IsEPCHagConformant\\\":false,\\\"Modulation\\\":0,\\\"ForwardLinkModulation\\\":0,\\\"SpectralMask\\\":0,\\\"BackscatterDataRate\\\":40000,\\\"PIERatio\\\":1500,\\\"MinTariTime\\\":6250,\\\"MaxTariTime\\\":6250,\\\"StepTariTime\\\":0}]},\\\"RFSurveyFrequencyCapabilities\\\":null},\\\"Custom\\\":null},\\\"C1G2LLRPCapabilities\\\":{\\\"SupportsBlockErase\\\":false,\\\"SupportsBlockWrite\\\":true,\\\"SupportsBlockPermalock\\\":false,\\\"SupportsTagRecommissioning\\\":false,\\\"SupportsUMIMethod2\\\":false,\\\"SupportsXPC\\\":false,\\\"MaxSelectFiltersPerQuery\\\":2},\\\"Custom\\\":null}\",\"valueType\":\"String\"}"
level=DEBUG ts=2021-06-30T00:00:01.00742426Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=ec9a6c76-aad1-4648-9838-18f29b990325 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-30T00:00:01.008427958Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ImpinjCustomExtensionMessage in the request parameters"
level=DEBUG ts=2021-06-30T00:00:01.00846993Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ImpinjCustomExtensionMessage"
level=DEBUG ts=2021-06-30T00:00:01.008502544Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ImpinjCustomExtensionMessage"
level=DEBUG ts=2021-06-30T00:00:01.008557436Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ImpinjCustomExtensionMessage Attributes:map[subtype:21 vendor:25882] Type:2}]"
level=DEBUG ts=2021-06-30T00:00:01.008590539Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgCustomMessage msg="Attempting send."
level=INFO ts=2021-06-30T00:00:01.00865011Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-30T00:00:01.008886997Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:00:01.008953063Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgCustomMessage device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:00:01.009129262Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ImpinjCustomExtensionMessage not found"
level=DEBUG ts=2021-06-30T00:00:01.00916893Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=b8c994d9-bd4c-466f-b075-24dc97791f22 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-30T00:00:01.009494161Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ReaderConfig in the request parameters"
level=DEBUG ts=2021-06-30T00:00:01.009562671Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ReaderConfig"
level=DEBUG ts=2021-06-30T00:00:01.009611208Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ReaderConfig"
level=DEBUG ts=2021-06-30T00:00:01.009669382Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ReaderConfig Attributes:map[] Type:2}]"
level=INFO ts=2021-06-30T00:00:01.009787058Z app=edgex-device-rfid-llrp source=device.go:234 forcedKA=30s msg="Adding device-service-enforced a KeepAlive spec to ReaderConfig."
level=DEBUG ts=2021-06-30T00:00:01.009842019Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgSetReaderConfig msg="Attempting send."
level=INFO ts=2021-06-30T00:00:01.009894677Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgSetReaderConfig device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=DEBUG ts=2021-06-30T00:00:01.010055442Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=ec9a6c76-aad1-4648-9838-18f29b990325 msg="SendEvent: Pushed event to core data"
level=INFO ts=2021-06-30T00:00:01.010212435Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:00:01.010254268Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgSetReaderConfigResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:00:01.010457633Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=a8e45101-97f6-4008-8999-80ab920b3bfe msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-30T00:00:01.010748784Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ROSpecID in the request parameters"
level=DEBUG ts=2021-06-30T00:00:01.010786496Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for Action in the request parameters"
level=DEBUG ts=2021-06-30T00:00:01.010813174Z app=edgex-device-rfid-llrp source=command.go:451 msg="there is no Action in the request parameters, retrieving value from the Parameter field from the ResourceOperation"
level=DEBUG ts=2021-06-30T00:00:01.010843902Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ROSpecID"
level=DEBUG ts=2021-06-30T00:00:01.010867158Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ROSpecID"
level=DEBUG ts=2021-06-30T00:00:01.010896909Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: Action"
level=DEBUG ts=2021-06-30T00:00:01.010923656Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: Action"
level=DEBUG ts=2021-06-30T00:00:01.01084488Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=b8c994d9-bd4c-466f-b075-24dc97791f22 msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-30T00:00:01.010963743Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ROSpecID Attributes:map[] Type:7} {DeviceResourceName:Action Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-30T00:00:01.010998731Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgDeleteROSpec msg="Attempting send."
level=INFO ts=2021-06-30T00:00:01.011036513Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgDeleteROSpec device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-30T00:00:01.01141922Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgDeleteROSpecResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:00:01.011467617Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgDeleteROSpecResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:00:01.011596118Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ROSpecID not found"
level=DEBUG ts=2021-06-30T00:00:01.011652197Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=01e26c8f-f75c-40b2-bcbe-fdeffb732aa9 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-30T00:00:01.011698359Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=a8e45101-97f6-4008-8999-80ab920b3bfe msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-30T00:00:01.012644163Z app=edgex-device-rfid-llrp source=command.go:441 msg="looking for ROSpec in the request parameters"
level=DEBUG ts=2021-06-30T00:00:01.012723847Z app=edgex-device-rfid-llrp source=command.go:396 msg="Handler - execWriteCmd: putting deviceResource: ROSpec"
level=DEBUG ts=2021-06-30T00:00:01.012950817Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=01e26c8f-f75c-40b2-bcbe-fdeffb732aa9 msg="SendEvent: Pushed event to core data"
level=ERROR ts=2021-06-30T00:00:01.013734669Z app=edgex-device-rfid-llrp source=utils.go:302 msg="Failed to update last connected value for device: SpeedwayR-11-25-D6"
level=ERROR ts=2021-06-30T00:00:01.013867778Z app=edgex-device-rfid-llrp source=utils.go:302 msg="Failed to update last connected value for device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-30T00:00:01.029697681Z app=edgex-device-rfid-llrp source=command.go:403 msg="Handler - execWriteCmd: putting deviceResource: ROSpec"
level=DEBUG ts=2021-06-30T00:00:01.02977988Z app=edgex-device-rfid-llrp source=driver.go:340 msg="LLRP-Driver.HandleWriteCommands: device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] reqs: [{DeviceResourceName:ROSpec Attributes:map[] Type:2}]"
level=DEBUG ts=2021-06-30T00:00:01.029871715Z app=edgex-device-rfid-llrp source=device.go:244 device=SpeedwayR-11-25-D6 message=MsgAddROSpec msg="Attempting send."
level=INFO ts=2021-06-30T00:00:01.029923255Z app=edgex-device-rfid-llrp source=logging.go:25 type=MsgAddROSpec device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-30T00:00:01.030095683Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgAddROSpecResponse device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:00:01.030141705Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgAddROSpecResponse device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:00:01.030279634Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=7115b33d-a544-4d6c-bf99-ec51624b144f msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-30T00:00:01.031259169Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=7115b33d-a544-4d6c-bf99-ec51624b144f msg="SendEvent: Pushed event to core data"
level=DEBUG ts=2021-06-30T00:00:31.01132257Z app=edgex-device-rfid-llrp source=logging.go:32 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:00:31.011443458Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:00:31.011542976Z app=edgex-device-rfid-llrp source=logging.go:23 type=MsgKeepAliveAck device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=DEBUG ts=2021-06-30T00:01:01.038888526Z app=edgex-device-rfid-llrp source=logging.go:32 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:01:01.038992723Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:01:01.039106487Z app=edgex-device-rfid-llrp source=logging.go:23 type=MsgKeepAliveAck device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=DEBUG ts=2021-06-30T00:01:31.039689511Z app=edgex-device-rfid-llrp source=logging.go:32 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:01:31.039818151Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgKeepAlive device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=DEBUG ts=2021-06-30T00:01:31.039922348Z app=edgex-device-rfid-llrp source=logging.go:23 type=MsgKeepAliveAck device=SpeedwayR-11-25-D6 msg="Sending LLRP message"
level=INFO ts=2021-06-30T00:01:32.134968447Z app=edgex-device-rfid-llrp source=logging.go:34 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Incoming LLRP message"
level=DEBUG ts=2021-06-30T00:01:32.13513417Z app=edgex-device-rfid-llrp source=logging.go:45 type=MsgReaderEventNotification device=SpeedwayR-11-25-D6 msg="Handled LLRP message."
level=ERROR ts=2021-06-30T00:01:32.135271191Z app=edgex-device-rfid-llrp source=device.go:166 error="failed to get next message: failed to read header: EOF" device=SpeedwayR-11-25-D6 msg="Client disconnected unexpectedly."
level=DEBUG ts=2021-06-30T00:01:32.135369382Z app=edgex-device-rfid-llrp source=async.go:97 msg="processAsyncResults - getting resource operation failed: specified ResourceOperation by deviceResource ReaderEventNotification not found"
2021/06/29 17:01:32 retry attempt: 1, wait: 0s
level=DEBUG ts=2021-06-30T00:01:32.135483216Z app=edgex-device-rfid-llrp source=utils.go:87 X-Correlation-ID=1bc16fff-dd54-4ddd-b6f1-e4c67db85697 msg="SendEvent: EventClient.MarshalEvent encoded event"
level=DEBUG ts=2021-06-30T00:01:32.135570024Z app=edgex-device-rfid-llrp source=device.go:139 address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Attempting to dial Reader."
level=ERROR ts=2021-06-30T00:01:32.135925355Z app=edgex-device-rfid-llrp source=device.go:144 error="dial tcp 10.0.0.53:5084: connect: connection refused" address=10.0.0.53:5084 device=SpeedwayR-11-25-D6 msg="Failed to dial Reader."
level=WARN ts=2021-06-30T00:01:32.136003293Z app=edgex-device-rfid-llrp source=device.go:197 device=SpeedwayR-11-25-D6 msg="Failed to connect to Device after multiple tries."
level=DEBUG ts=2021-06-30T00:01:32.136075854Z app=edgex-device-rfid-llrp source=manageddevices.go:127 msg="Updating managed Device: : SpeedwayR-11-25-D6\n"
level=DEBUG ts=2021-06-30T00:01:32.13787381Z app=edgex-device-rfid-llrp source=utils.go:97 Content-Type=application/json X-Correlation-ID=1bc16fff-dd54-4ddd-b6f1-e4c67db85697 msg="SendEvent: Pushed event to core data"
2021/06/29 17:01:32 retry attempt: 7, wait: 7m0s
level=INFO ts=2021-06-30T00:01:32.151730536Z app=edgex-device-rfid-llrp source=device.go:119 msg="Updated device: SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-30T00:01:32.151771601Z app=edgex-device-rfid-llrp source=driver.go:640 msg="Updating device: SpeedwayR-11-25-D6 protocols: map[tcp:map[host:10.0.0.53 port:5084]] adminState: UNLOCKED"
level=DEBUG ts=2021-06-30T00:01:32.151803167Z app=edgex-device-rfid-llrp source=device.go:129 msg="Invoked driver.UpdateDevice callback for SpeedwayR-11-25-D6"
level=DEBUG ts=2021-06-30T00:01:32.151818322Z app=edgex-device-rfid-llrp source=device.go:136 msg="Handler - restarting AutoEvents for updated device SpeedwayR-11-25-D6"

RetryWithContext.go

// RetryWithCtx works like RetrySome, but allows a custom context,
// which may be used to cancel during waits between attempts.
// The context is passed to f unmodified.
//
// Regardless of the return values of f, if the context is canceled,
// Retry will not continue calling f;
// however, Retry can only check the context between calls to f.
// It is up to f to determine how/if to use the context.
// For short lived functions the don't await any signals,
// it's fine to ignore the context.
// For functions that block waiting on, e.g., a network resource,
// they should add ctx.Done to their select statements.
//
// In most cases, it's not really necessary for f to check ctx immediately.
// Before calls to f, Retry checks if ctx is canceled, past its Deadline,
// or if its Deadline would occur before the next call to f.
// In these cases, it adds ctx.Err to its accumulated errors and returns.
// As a result, at the beginning of f's execution,
// it's unlikely (though possible) that ctx is canceled or past its deadline.
func (ebo ExpBackOff) RetryWithCtx(ctx context.Context, retries int, f Func) error {
	// Check if the context is already expired.
	if ctxErr := ctx.Err(); ctxErr != nil {
		return &FError{MainErr: ctxErr}
	}

	// if f is successful, avoid all the other work
	cont, err := f(ctx)
	if err == nil {
		return nil
	}

	// the retry error to collect f's errors; we'll return this if f never returns non-nil
	// re := &FError{Latest: err}
	re := newFError(err, ebo.KeepErrs)
	if !cont {
		re.MainErr = ErrRetriesExceeded
		return re
	}

	if ebo.Max <= 0 {
		ebo.Max = math.MaxInt64
	}

	if ebo.BackOff <= 0 {
		ebo.BackOff = 1
	}

	// Create a timer, but immediately stop it (and drain it if necessary).
	// Go Timers have a bit of an annoying API,
	// and they require a lot of care to prevent resource leaks and deadlock.
	delay := time.NewTimer(ebo.BackOff)
	if !delay.Stop() {
		<-delay.C
	}

	deadline, hasDeadline := ctx.Deadline()

	// start at 1 since we've already tried once
	for attempt := 1; retries == Forever || attempt < retries; attempt++ {
		wait := ebo.nextWait(attempt)
		if hasDeadline && time.Now().Add(wait).After(deadline) {
			re.MainErr = ErrWaitExceedsDeadline
			return re
		}

		log.Printf("retry attempt: %d, wait: %v", attempt, wait)
		delay.Reset(wait)

		// wait for next attempt
		select {
		case <-ctx.Done():
			re.MainErr = ctx.Err()
			if !delay.Stop() {
				<-delay.C
			}
			return re
		case <-delay.C:
		}

		// try the operation
		cont, err = f(ctx)
		if err == nil {
			log.Printf("retry succeeded on attempt: %d", attempt)
			return nil
		}

		if !cont {
			re.MainErr = err
			return re
		}

		re.addErr(err)
	}

	re.MainErr = ErrRetriesExceeded
	return re
}