I checked my logs and don't see any messages like that. But, I cleared the logs about an hour ago.
I'll look again tomorrow.
Well it happened again. Today around 3 pm. I wasn’t home so not sure if anything else affected.
app:3022021-06-03 06:12:40.127 pm info EchoApp (v4.1.7.0) | running initialize...
app:3022021-06-03 06:12:39.852 pm info EchoApp (v4.1.7.0) | Updated Event Received...
app:3022021-06-03 03:00:25.558 pm errorEchoApp (v4.1.7.0) | DnDResp Exception: java.lang.Exception: No response data exists for async request
app:3022021-06-03 03:00:25.553 pm errorEchoApp (v4.1.7.0) | DnDResp | Stack Trace: java.lang.Exception: No response data exists for async request at user_app_tonesto7_Echo_Speaks_212.DnDResp(user_app_tonesto7_Echo_Speaks_212.groovy:2779)
app:3022021-06-03 03:00:25.484 pm warn EchoApp (v4.1.7.0) | 408 DnDResp
app:3022021-06-01 01:16:27.026 pm info EchoApp (v4.1.7.0) | running initialize...
app:3022021-06-01 01:16:26.946 pm info EchoApp (v4.1.7.0) | Updated Event Received...
app:3022021-06-01 06:54:31.084 am errorEchoApp (v4.1.7.0) | DnDResp Exception: java.lang.Exception: No response data exists for async request
app:3022021-06-01 06:54:31.037 am errorEchoApp (v4.1.7.0) | getBluetoothResp Exception: java.lang.Exception: No response data exists for async request
app:3022021-06-01 06:54:31.032 am errorEchoApp (v4.1.7.0) | getBluetoothResp | Stack Trace: java.lang.Exception: No response data exists for async request at user_app_tonesto7_Echo_Speaks_212.getBluetoothResp(user_app_tonesto7_Echo_Speaks_212.groovy:2625)
app:3022021-06-01 06:54:31.017 am errorEchoApp (v4.1.7.0) | DnDResp | Stack Trace: java.lang.Exception: No response data exists for async request at user_app_tonesto7_Echo_Speaks_212.DnDResp(user_app_tonesto7_Echo_Speaks_212.groovy:2779)
app:3022021-06-01 06:54:30.929 am warn EchoApp (v4.1.7.0) | 408 getBluetoothResp
app:3022021-06-01 06:54:30.928 am warn EchoApp (v4.1.7.0) | 408 DnDResp
And once again seems to have self healed. No further errors. If the general consensus is a crummy internet connection, I’ll just have to live with it for now.
I don't see any log entries with "EchoApp". But lots of them with "Echo(v4.1.7.0)". Weird that we have the same version, but slightly different message.
I have messages like this:
dev:812021-06-03 07:47:05.902 am warnEcho (v4.1.7.0) | Commands NOT Allowed! Device is currently (OFFLINE) | Type: (volumeControl)
But nothing with the 408 or getBluethoothResp -- my Echo/Spot devices aren't using Bluetooth.
Well that may be information I can use. If I lost power (or internet) several of the Alexa devices maybe trying to re-connect. Since I almost never use Alexa with bluetooth, I'll go through the Alexa app and tell all devices to forget bluetooth. Any idea what the 408 error is? (other than my local area code)
408 is an HTTP timeout...
Hmm, this seems to support it's a result of my crummy internet. At least this tells me to ignore it as I cannot do anything about my internet.
Thanks
Is it Spectrum by chance? Before switching to AT&T fiber we had Spectrum and this is one of the reasons we don’t anymore. I recently had to get Spectrum at a house I inherited in order to keep an eye on it and it is so problematic that I had to install a TP-Link outlet to reboot the internet daily. The modem becomes unresponsive to even ISP initiated reboots. I was super thrilled to make the 8.5 hour drive to do that. It still cuts out almost every day for 20 or so minutes.
Nah, I have AT&T, but it's like DSL, coming over the twisted pair phone lines. I live in a mobile home park that does not have any cable network and they won't spend the money to upgrade, Since the park owns the distribution network, I'm stuck until something like Verizon 5G offers home internet in my area (it's available about 2 miles away) Someday 
2 Likes
That is very surprising, were you using the Spectrum provided modem and router? In my experience Spectrum is one of the best simply because they give you the freedom of choosing your own hardware. They don't lock you down like AT&T does with their awful gateways.
Modem only. Netgear X6S router connected. The modem is what needs rebooted daily although the Netgear was resurrected from my drawer of shame for this need.
I was able to easily bypass the gateway router and use my own. I have also only had two service interruptions in about 3 years.
I'm having trouble setting up and action trigger based on a temperature. It was suggested I repost my issue here:
Also,
I set up a rule (Rules4 app) to speak the temperature when it exceeds the threshold. The rule triggers when I refresh the Pool Temperature device. So, I think that means the Pool Controller Body device driver is sending the correct event, at least when refreshed.
The same refresh does NOT trigger the Echo Speaks app's action.
Actually, now I can get the EchoSpeaks action to trigger and speak the correct temperature.
I don't know why it started working. Maybe I wasn't refreshing the correct device?
Next, I need to figure out what causes the refresh method to activate in the Pool Controller Body driver, or do the sendEvent whenever temperature changes.
It will good to post more of the logs when you do share them.
ie turn on all logs, as there will be trace events that show what ES received from the device (which were missing from your earlier post).
ES can only react to event it gets from the device. When you enable repeats in ES, it can repeat an event it received earlier, but even then for this to start it must receive an event.
You are correct when you run a test, it creates a made up value (randomly) so you can see how things execute with different values.
And now, it's not working (again). Here's a log when I do the refresh:
dev:972021-06-09 02:02:43.737 pm debugHeater Modes [Off, Heater]
dev:972021-06-09 02:02:43.619 pm debugSend GET to with [uri:http://192.168.0.224:4200, path:/config/body/1/heatModes, requestContentType:application/json, contentType:application/json, body:null] CB=parseHeatModes
dev:972021-06-09 02:02:43.577 pm debugCurrent body - [id:1, heaterOptions:[total:1, gas:1, solar:0, heatpump:0, ultratemp:0, hybrid:0, maxetherm:0, mastertemp:0], type:[val:0, name:pool, desc:Pool], temp:89, isOn:true, setPoint:85, name:pool, circuit:6, heatMode:[val:0, name:off, desc:Off], heatStatus:[val:0, name:off, desc:Off]] id=1-
dev:972021-06-09 02:02:43.570 pm debugparseBodies - [[id:1, heaterOptions:[total:1, gas:1, solar:0, heatpump:0, ultratemp:0, hybrid:0, maxetherm:0, mastertemp:0], type:[val:0, name:pool, desc:Pool], temp:89, isOn:true, setPoint:85, name:pool, circuit:6, heatMode:[val:0, name:off, desc:Off], heatStatus:[val:0, name:off, desc:Off]]]
dev:972021-06-09 02:02:43.561 pm debugWater temperature is 89
dev:972021-06-09 02:02:43.558 pm debugparseTemps - [units:[val:0, name:F, desc:Fahrenheit], bodies:[[id:1, heaterOptions:[total:1, gas:1, solar:0, heatpump:0, ultratemp:0, hybrid:0, maxetherm:0, mastertemp:0], type:[val:0, name:pool, desc:Pool], temp:89, isOn:true, setPoint:85, name:pool, circuit:6, heatMode:[val:0, name:off, desc:Off], heatStatus:[val:0, name:off, desc:Off]]], waterSensor1:89, air:89, solar:88, equipmentType:temps]
dev:972021-06-09 02:02:43.506 pm debugSend GET to with [uri:http://192.168.0.224:4200, path:/state/temps, requestContentType:application/json, contentType:application/json, body:null] CB=parseTemps
Based on the log entry "Water temperature is 89", I know the sendEvent in the Pool Controller Body is being executed:
if (temps.waterSensor1) {
logger("Water temperature is ${temps.waterSensor1.value}")
sendEvent([name: "temperature", value: temps.waterSensor1.value.toInteger(), unit: state.units])
//logger(temps.waterSensor1.value)
}
But I don't see it in the Pool Controller Body device event list (I've done the refresh and seen the log entry above several times since 1:59. (Everything worked at 1:59)
(Echo Speaks logs are all checked on--but not the child logging)
Dev97 is the pool controller body device.
So, I don't understand why events are NOT showing up in the device event list, even though I know the sendEvent got called.
Here is a log trace when I think it worked (can't be sure if that was the one):
app:852021-06-09 01:58:28.046 pm debugEchoApp (v4.1.8.0) | getDeviceActivity: Process Time: (286ms)
app:852021-06-09 01:58:27.761 pm traceEchoApp (v4.1.8.0) | getDeviceActivity(null, true)
app:852021-06-09 01:58:25.933 pm debugEchoApp (v4.1.8.0) | workQ active: false work items fnd: false now: 1623261505932 nextOk: 1623261509600
app:852021-06-09 01:58:25.930 pm traceEchoApp (v4.1.8.0) | running workQ
app:852021-06-09 01:58:25.897 pm traceEchoApp (v4.1.8.0) | running finishWorkQ
app:852021-06-09 01:58:25.616 pm debugEchoApp (v4.1.8.0) | workQ active: true work items fnd: true now: 1623261505616 nextOk: 1623261509600
app:852021-06-09 01:58:25.606 pm debugEchoApp (v4.1.8.0) | workQ FINAL ms delay is 4000.0
app:852021-06-09 01:58:25.605 pm debugEchoApp (v4.1.8.0) | workQ ms delay is 4000.0
app:852021-06-09 01:58:25.603 pm debugEchoApp (v4.1.8.0) | workQ adding sendSpeak from 85|echoSpeaks|G070RQ139185002G | MultiSequence : Sequential
app:852021-06-09 01:58:25.588 pm traceEchoApp (v4.1.8.0) | running workQ
app:852021-06-09 01:58:25.307 pm debugaddToQ (multi) | Command(1): [command:speak, value:Spa temperature is 0 degrees., deviceData:[deviceType:A10A33FOX2NUBK, serialNumber:G070RQ139185002G, owner:A2USDQEK8XS6EB, account:A06170443BL3Z3EJ1IV9V, dni:85|echoSpeaks|G070RQ139185002G], cmdType:sendSpeak]
app:852021-06-09 01:58:25.305 pm debugaddToQ (multi) | srcDesc: sendSpeak from 85|echoSpeaks|G070RQ139185002G
app:852021-06-09 01:58:25.304 pm debugaddToQ (multi) | callback: finishSendSpeak
app:852021-06-09 01:58:25.303 pm debugaddToQ (multi) | device: 85|echoSpeaks|G070RQ139185002G
app:852021-06-09 01:58:25.302 pm debugaddToQ (multi) | time: 1623261505242
app:852021-06-09 01:58:25.299 pm debugaddToQ (multi) | cmdMap: [cmdDesc:SpeakCommand, message:Spa temperature is 0 degrees., newVolume:null, oldVolume:null, cmdDt:1623261505196, cmdId:230, deviceType:A10A33FOX2NUBK, serialNumber:G070RQ139185002G, owner:A2USDQEK8XS6EB, account:A06170443BL3Z3EJ1IV9V, dni:85|echoSpeaks|G070RQ139185002G]
app:852021-06-09 01:58:25.298 pm debugaddToQ NEW COMMAND (1)
app:852021-06-09 01:58:25.236 pm traceEchoApp (v4.1.8.0) | sendSpeak cmdMap: [cmdDesc:SpeakCommand, message:Spa temperature is 0 degrees., newVolume:null, oldVolume:null, cmdDt:1623261505196, cmdId:230, deviceType:A10A33FOX2NUBK, serialNumber:G070RQ139185002G, owner:A2USDQEK8XS6EB, account:A06170443BL3Z3EJ1IV9V, dni:85|echoSpeaks|G070RQ139185002G] callback: finishSendSpeak, device: 85|echoSpeaks|G070RQ139185002G
app:1302021-06-09 01:58:25.135 pm infoAction: Speak on Echo - Family: 'Spa temperature is %value% degrees.'
dev:972021-06-09 01:57:52.220 pm debugHeater Modes [Off, Heater]
dev:972021-06-09 01:57:52.167 pm debugSend GET to with [uri:http://192.168.0.224:4200, path:/config/body/1/heatModes, requestContentType:application/json, contentType:application/json, body:null] CB=parseHeatModes
dev:972021-06-09 01:57:52.127 pm debugCurrent body - [id:1, heaterOptions:[total:1, gas:1, solar:0, heatpump:0, ultratemp:0, hybrid:0, maxetherm:0, mastertemp:0], type:[val:0, name:pool, desc:Pool], temp:89, isOn:true, setPoint:85, name:pool, circuit:6, heatMode:[val:0, name:off, desc:Off], heatStatus:[val:0, name:off, desc:Off]] id=1-
dev:972021-06-09 01:57:52.118 pm debugparseBodies - [[id:1, heaterOptions:[total:1, gas:1, solar:0, heatpump:0, ultratemp:0, hybrid:0, maxetherm:0, mastertemp:0], type:[val:0, name:pool, desc:Pool], temp:89, isOn:true, setPoint:85, name:pool, circuit:6, heatMode:[val:0, name:off, desc:Off], heatStatus:[val:0, name:off, desc:Off]]]
dev:972021-06-09 01:57:52.110 pm debug89
dev:972021-06-09 01:57:52.108 pm debugWater temperature is 89
dev:972021-06-09 01:57:52.104 pm debugparseTemps - [units:[val:0, name:F, desc:Fahrenheit], bodies:[[id:1, heaterOptions:[total:1, gas:1, solar:0, heatpump:0, ultratemp:0, hybrid:0, maxetherm:0, mastertemp:0], type:[val:0, name:pool, desc:Pool], temp:89, isOn:true, setPoint:85, name:pool, circuit:6, heatMode:[val:0, name:off, desc:Off], heatStatus:[val:0, name:off, desc:Off]]], waterSensor1:89, air:88, solar:88, equipmentType:temps]
So HE does not sendEvents if the value would be the same as the current value.
So your sendEvent does nothing if the temperature attribute is already that value. If it does nothing, no event was sent.
This is proper coding for a device - ie it should not send events when nothing changed.
Also note, if debugging an Action, only need full logs for the action unless otherwise asked....it helps narrow the search.
2 Likes
I see. That explains much.
So, sendEvent itself keeps track of what was sent last? I don't see code in the driver that keeps track of current state and does the sendEvent only if it is different.
correct that is built into the sendEvent method. There is a way to force it to send the event, but that is bad form for anything that is not a momentary device.
So, I'm thinking about how to implement what I want, given how events aren't sent if there's no change.
I was thinking the Echo Speaks action would run constantly with delay of 10 or 20 seconds between each speak, until a virtual switch was turned off. And, if the temperature was already above the threshold set in the rule/Action trigger, it should trigger, even if it's been at that temperature for hours.
