Notification sent to timed out

[Xenomes]

Hi,

My Pi system is running Domoticz 4.10570 and the latest Google plugin of 20-3-2019 I am unable to send a notification to my Google Home Mini. The mp3 file is created and external it is playable, but not sent to the google home I get this error message. Error: (Google Home) Notification 'Test knop', sent to 'Google Huiskamer' timed out I don't know what to do get it working.

My setting are

Here is a part of the log:

2019-03-25 21:29:52.581 (Google Home) Pushing 'onHeartbeatCallback' on to queue 2019-03-25 21:29:52.624 (Google Home) Processing 'onHeartbeatCallback' message 2019-03-25 21:29:52.624 (Google Home) Calling message handler 'onHeartbeat'. 2019-03-25 21:30:00.158 (Google Home) Pushing 'onNotificationCallback' on to queue 2019-03-25 21:30:00.158 Notification sent (Google_Devices) => Success 2019-03-25 21:30:00.169 (Schakelaars) Light/Switch (Test Knop) 2019-03-25 21:30:00.187 (Google Home) Processing 'onNotificationCallback' message 2019-03-25 21:30:00.188 (Google Home) Calling message handler 'onNotification'. 2019-03-25 21:30:00.188 (Google Home) onNotification: Test Knop,Test knop,Test knop,On,0,,/home/pi/domoticz/www/images/Generic48_On.png 2019-03-25 21:30:00.189 (Google Home) handleMessage: 'Test knop', sent to 'Google Huiskamer' 2019-03-25 21:30:00.494 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:00.502 (Google Home) [Google Home - Google Home Volume] Update 2(2):'69'(50): 0(0) 2019-03-25 21:30:00.502 (Google Home - Google Home Volume) Updating device from 2:'50' to have values 2:'69'. 2019-03-25 21:30:00.995 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:00.155 Status: User: Xenomes initiated a switch command (131/Test Knop/On) 2019-03-25 21:30:00.158 Status: Notification: Test knop 2019-03-25 21:30:01.496 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:01.996 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:02.409 Notification sent (email) => Success 2019-03-25 21:30:02.496 (Google Home) [Google Home - Google Home Volume] Update 0(2):'69'(69): 0(0) 2019-03-25 21:30:02.496 (Google Home - Google Home Volume) Updating device from 2:'69' to have values 0:'69'. 2019-03-25 21:30:02.583 (Google Home) Pushing 'onHeartbeatCallback' on to queue 2019-03-25 21:30:02.593 (Google Home) Processing 'onHeartbeatCallback' message 2019-03-25 21:30:14.317 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:14.324 (Google Home) [Google Home - Google Home Status] Update 9(9):'Screensaver'(Screensaver): 1(0) 2019-03-25 21:30:14.325 (Google Home - Google Home Status) Updating device from 9:'Screensaver' to have values 9:'Screensaver'. 2019-03-25 21:30:14.324 Status: (Google Home) Google Huiskamer is now: LOST 2019-03-25 21:30:15.326 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:15.827 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:16.328 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:16.828 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:17.329 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:17.830 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:18.331 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:18.832 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:19.332 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:20.334 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:20.835 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:21.336 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:21.836 (Google Home) Waiting for 'Default Media Receiver' to start 2019-03-25 21:30:22.355 (Google Home) [Google Home - Google Home Volume] Update 0(0):'50'(69): 0(0) 2019-03-25 21:30:22.356 (Google Home - Google Home Volume) Updating device from 0:'69' to have values 0:'50'. 2019-03-25 21:30:22.389 (Google Home) [Google Home - Google Home Volume] Update 2(0):'50'(50): 0(0) 2019-03-25 21:30:22.389 (Google Home - Google Home Volume) Updating device from 0:'50' to have values 2:'50'. 2019-03-25 21:30:22.341 Error: (Google Home) Notification 'Test knop', sent to 'Google Huiskamer' timed out 2019-03-25 21:30:23.891 (Google Home) Pushing 'onHeartbeatCallback' on to queue 2019-03-25 21:30:23.910 (Google Home) Processing 'onHeartbeatCallback' message 2019-03-25 21:30:23.911 (Google Home) Calling message handler 'onHeartbeat'. 2019-03-25 21:30:33.893 (Google Home) Pushing 'onHeartbeatCallback' on to queue 2019-03-25 21:30:33.927 (Google Home) Processing 'onHeartbeatCallback' message 2019-03-25 21:30:33.928 (Google Home) Calling message handler 'onHeartbeat'.

[dnpwwo]

Key line for me in this log is:

2019-03-25 21:30:14.324 Status: (Google Home) Google Huiskamer is now: LOST

which means that the library the plugin uses can't communicate with the home device at that exact point in time. You can't play audio on a device you can't talk to.

Does this always happen or was it a once off? You should see it trying to re-establish communication 5-10 seconds after this message. Was it successful?

[Xenomes]

The error message is always the same, when sending a notification. I am not seeing a retry in the log. The Google home make two sound b.t.w. one soft beep for volume change and a longer sound beep/string when you expect the notification being played. Other function on the Google home works normal.

[dnpwwo]

I've pushed a new version tonight that changes the media type and how the plugin waits. Might help.

[Xenomes]

Sorry had no time to test the last days. The error message is gone. The mp3 file is not played, but there is a extra beep for the volume back to original.

[dnpwwo]

Can you try the latest version and close the issue if it is now resolved?

[Xenomes]

I have follow the other Notification issue, there is sometimes the message in the log. 2019-04-13 07:46:41.987 Error: (Google Home) Notification sent to 'Google Huiskamer' timed out 2019-04-13 08:02:00.061 (Google Home) Notification sent to 'Google Huiskamer' completed

I have updated pychromecast to 3.20, installed gtts and update your script. But the mp3 file is not being played. Part of the log: new 2.txt

[jeroenkl]

I've got the same issue. Update to latest version didn't fix it 1.16.13 - Bugfix: Handle groups changing 'elected leader'

best regards, Jeroen

[dnpwwo]

I assume you have you Domoticz set to use Dutch so I set my test system to match and the test message played in Dutch. With the logging level set to 'Python Only' I got:

2019-04-14 17:31:25.339 (Google Devices) onCommand called for Unit 2: Parameter 'SendNotification Dit is een test bericht', Level: 0 2019-04-14 17:31:25.340 (Google Devices) UUID: 9c72b737-74fb-8e34-5ceb-10ba04302cc2, sub unit: -1, Action: Sendnotification, params: Dit is een test bericht 2019-04-14 17:31:25.340 (Google Devices) handleMessage: 'Dit is een test bericht', to be sent to 'Lounge Speaker' 2019-04-14 17:31:27.886 (Google Devices) [Lounge Home - Volume] Update 2(2):'40'(37): 0(0) 2019-04-14 17:31:28.034 (Google Devices) [Lounge Home - Volume] Update 0(2):'40'(40): 0(0) 2019-04-14 17:31:28.212 (Google Devices) xxx.xxx.xxx.xxx:40506 Connection established 2019-04-14 17:31:28.213 (Google Devices) xxx.xxx.xxx.xxx:40506 Sent 'GET' request file '/message.mp3' from position 0 2019-04-14 17:31:28.345 (Google Devices) [Lounge Home - Volume] Update 2(0):'40'(40): 0(0) 2019-04-14 17:31:28.351 (Google Devices) [Lounge Home - Playing] Update 2(0):'1'(0): 0(0) 2019-04-14 17:31:28.516 (Google Devices) xxx.xxx.xxx.xxx:40506 Connection disconnected 2019-04-14 17:31:28.880 (Google Devices) Waiting for message to complete playing (timeout in 69.9 seconds) 2019-04-14 17:31:29.381 (Google Devices) Waiting for message to complete playing (timeout in 69.4 seconds) 2019-04-14 17:31:29.882 (Google Devices) Waiting for message to complete playing (timeout in 68.9 seconds) 2019-04-14 17:31:30.383 (Google Devices) Waiting for message to complete playing (timeout in 68.4 seconds) 2019-04-14 17:31:30.823 (Google Devices) [All Speakers - Volume] Update 2(2):'44'(43): 0(0) 2019-04-14 17:31:30.830 Status: LUA: Device based event fired on 'All Speakers - Volume', value 'Set Level: 44 %' 2019-04-14 17:31:30.842 (Google Devices) [Google Devices - Downstairs Speakers Volume] Update 2(2):'45'(44): 0(0) 2019-04-14 17:31:30.884 (Google Devices) Waiting for message to complete playing (timeout in 67.9 seconds) 2019-04-14 17:31:31.385 (Google Devices) Waiting for message to complete playing (timeout in 67.4 seconds) 2019-04-14 17:31:31.864 (Google Devices) [Lounge Home - Playing] Update 2(2):'44'(1): 0(0) 2019-04-14 17:31:31.886 (Google Devices) Waiting for message to complete playing (timeout in 66.9 seconds) 2019-04-14 17:31:32.387 (Google Devices) Waiting for message to complete playing (timeout in 66.4 seconds) 2019-04-14 17:31:32.888 (Google Devices) Waiting for message to complete playing (timeout in 65.9 seconds) 2019-04-14 17:31:32.953 (Google Devices) [Lounge Home - Volume] Update 0(2):'40'(40): 0(0) 2019-04-14 17:31:32.959 (Google Devices) [Lounge Home - Playing] Update 0(2):'0'(44): 0(0) 2019-04-14 17:31:33.390 (Google Devices) Notification sent to 'Lounge Speaker' completed

What it shows is that for you the Google Home never came back to ask for the file. For me it did (lines in bold show the file being served). Either you have a firewall blocking it or you just tested too early.

Try starting Domoticz, waiting until all the devices aren't 'red' anymore and then retest.

[jeroenkl]

Hi dnpwwo,

Yes, Domoticz in Dutch, latest beta running.

Log: 2019-04-14 15:18:20.664 Notification sent (Google_Devices) => Success 2019-04-14 15:18:20.705 (Google Home) onNotification: Ikea - Lamp stoel,Lamp stoel is aangegaan,Lamp stoel is aangegaan,On,0,,/home/pi/domoticz/www/images/Uplighter48_On.png 2019-04-14 15:18:20.706 (Google Home) handleMessage: 'Lamp stoel is aangegaan', to be sent to 'Huiskamer' 2019-04-14 15:18:22.255 (Google Home) [Google Home - Huiskamer Volume] Update 2(2):'50'(40): 0(0) 2019-04-14 15:18:22.287 (Google Home) [Google Home - Thuisgroep Volume] Update 2(2):'50'(40): 0(0) 2019-04-14 15:18:22.498 (Google Home) [Google Home - Huiskamer Volume] Update 0(2):'50'(50): 0(0) 2019-04-14 15:18:23.533 (Google Home) Waiting for player (timeout in 69.99989581108093 seconds) 2019-04-14 15:18:24.034 (Google Home) Waiting for player (timeout in 69.49892044067383 seconds) 2019-04-14 15:18:24.535 (Google Home) Waiting for player (timeout in 68.99799799919128 seconds) 2019-04-14 15:18:25.036 (Google Home) Waiting for player (timeout in 68.49691390991211 seconds) 2019-04-14 15:18:25.537 (Google Home) Waiting for player (timeout in 67.99588465690613 seconds) 2019-04-14 15:18:26.038 (Google Home) Waiting for player (timeout in 67.49488091468811 seconds) 2019-04-14 15:18:26.539 (Google Home) Waiting for player (timeout in 66.99395608901978 seconds) 2019-04-14 15:18:27.040 (Google Home) Waiting for player (timeout in 66.49302196502686 seconds) 2019-04-14 15:18:27.541 (Google Home) Waiting for player (timeout in 65.99213886260986 seconds) 2019-04-14 15:18:28.042 (Google Home) Waiting for player (timeout in 65.4912486076355 seconds) 2019-04-14 15:18:29.044 (Google Home) Waiting for player (timeout in 64.48930215835571 seconds) 2019-04-14 15:18:29.545 (Google Home) Waiting for player (timeout in 63.98833131790161 seconds) 2019-04-14 15:18:30.046 (Google Home) Waiting for player (timeout in 63.4874382019043 seconds) 2019-04-14 15:18:30.547 (Google Home) Waiting for player (timeout in 62.98652768135071 seconds) 2019-04-14 15:18:31.048 (Google Home) Waiting for player (timeout in 62.485663175582886 seconds) 2019-04-14 15:18:31.548 (Google Home) Waiting for player (timeout in 61.98474621772766 seconds) 2019-04-14 15:18:32.049 (Google Home) Waiting for player (timeout in 61.48383975028992 seconds) 2019-04-14 15:18:32.550 (Google Home) Waiting for player (timeout in 60.982913970947266 seconds) 2019-04-14 15:18:33.051 (Google Home) Waiting for player (timeout in 60.48203730583191 seconds) 2019-04-14 15:18:34.053 (Google Home) Waiting for player (timeout in 59.480212926864624 seconds) 2019-04-14 15:18:34.554 (Google Home) Waiting for player (timeout in 58.97927236557007 seconds) 2019-04-14 15:18:35.055 (Google Home) Waiting for player (timeout in 58.47830605506897 seconds) 2019-04-14 15:18:35.556 (Google Home) Waiting for player (timeout in 57.9774067401886 seconds) 2019-04-14 15:18:36.057 (Google Home) Waiting for player (timeout in 57.47651195526123 seconds) 2019-04-14 15:18:36.558 (Google Home) Waiting for player (timeout in 56.975521087646484 seconds) 2019-04-14 15:18:37.059 (Google Home) Waiting for player (timeout in 56.47457432746887 seconds) 2019-04-14 15:18:37.559 (Google Home) Waiting for player (timeout in 55.97368264198303 seconds) 2019-04-14 15:18:38.060 (Google Home) Waiting for player (timeout in 55.47280430793762 seconds) 2019-04-14 15:18:39.062 (Google Home) Waiting for player (timeout in 54.4713659286499 seconds) 2019-04-14 15:18:39.563 (Google Home) Waiting for player (timeout in 53.97049689292908 seconds) 2019-04-14 15:18:40.063 (Google Home) Waiting for player (timeout in 53.46965146064758 seconds) 2019-04-14 15:18:40.564 (Google Home) Waiting for player (timeout in 52.96876239776611 seconds) 2019-04-14 15:18:41.065 (Google Home) Waiting for player (timeout in 52.46785068511963 seconds) 2019-04-14 15:18:41.566 (Google Home) Waiting for player (timeout in 51.96695685386658 seconds) 2019-04-14 15:18:42.067 (Google Home) Waiting for player (timeout in 51.4661009311676 seconds) 2019-04-14 15:18:42.568 (Google Home) Waiting for player (timeout in 50.96522331237793 seconds) 2019-04-14 15:18:43.069 (Google Home) Waiting for player (timeout in 50.46435022354126 seconds xxxx xxxx 2019-04-14 15:19:31.659 (Google Home) Waiting for player (timeout in 1.8742473125457764 seconds) 2019-04-14 15:19:32.160 (Google Home) Waiting for player (timeout in 1.373375415802002 seconds) 2019-04-14 15:19:32.661 (Google Home) Waiting for player (timeout in 0.8724842071533203 seconds) 2019-04-14 15:19:33.162 (Google Home) Waiting for player (timeout in 0.371610164642334 seconds) 2019-04-14 15:19:33.677 (Google Home) [Google Home - Huiskamer Volume] Update 0(0):'40'(50): 0(0) 2019-04-14 15:19:33.717 (Google Home) [Google Home - Thuisgroep Volume] Update 2(2):'40'(50): 0(0) 2019-04-14 15:19:33.758 (Google Home) [Google Home - Huiskamer Volume] Update 2(0):'40'(40): 0(0) 2019-04-14 15:19:33.669 Error: (Google Home) Notification sent to 'Huiskamer' timed out

No firewall in between, domoticz is rebooted.

[Xenomes]

My setup is working! The issue was a user error, i had enter the wrong IP in the field "Voice message IP address" :sweat: