Sound notifications not working on OH 5.2.X with Sonos and MaryTTS/Piper

[nelson.aponte]

Hi.

I’ve been running openHAB on my Raspberry Pi 4 on CentOS for years.

I recently updated OH from 5.1.3 to 5.2.1, and I stopped receiving sound notifications from OH on my Sonos One (the only Sonos product I have, and the only audio output I have). I cannot be sure if the issue is with the MaryTTS service or with Sonos. For years, I’ve had no issues with Sonos or MaryTTS, and I haven’t changed any configuration, except for the OH upgrade.

Symptoms

1. I don’t receive sound notifications sent from OH.
   1. When sending notifications from within JS rules, the rules don’t crash when they reach the notification, and the next steps are executed without problems.
2. I can control some Sonos features, such as the volume, bass, and LED light, but I no longer see what’s playing, plus the favorites list is no longer populated. The play/pause button on the controller doesn’t always work.

Configuration

Sonos

On the OH side, I added the Sonos One’s IP to the binding configuration, but that didn’t change anything.

The Sonos One thing is configured on the MainUI, and it’s online. I have deleted and added it back, but nothing has changed. I had not previously defined any Notification Sound Volume, but setting it to 30 didn’t change the fact that no notifications are played.

Most channels are connected to an item.

On the Sonos App, UnPn is ON. I tried changing the Authentication setting from OFF to ON, but nothing changed.

Voice

I have been using MaryTTS for 3 or 4 years now. Sometimes, when the default voice gets lost after an upgrade, notifications stop working, but after resetting it, they start working again. However, with this upgrade, nothing got lost.

Audio

The default sink is the Sonos One.

Logs

When I send a test notification from Karaf

openhab:voice say This is a test

Sonos stops playing whatever it’s playing, doesn’t say anything, and this is logged:

08:57:00.871 [DEBUG] [binding.sonos.internal.SonosAudioSink] - Audio stream accessible through HTTP served at /audio/XXXXXXXX-fX50-4a6c-a55d-XXXXXXXXXXXX for Sonos playback
08:57:00.872 [DEBUG] [os.internal.handler.ZonePlayerHandler] - playNotificationSoundURI: notificationURL http://10.XX.XX.124:8080/audio/XXXXXXXX-fX50-4a6c-a55d-XXXXXXXXXXXX.wav currentURI null metadata null
08:57:00.880 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Handling notification while loaded queue is empty: URL http://10.XX.XX.124:8080/audio/XXXXXXXX-fX50-4a6c-a55d-XXXXXXXXXXXX.wav coordinator RINCON_48A6B8D0150XXXXXX
08:57:00.880 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Apply notification volume
08:57:00.882 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Could not fetch Sonos group state information
08:57:00.882 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Could not fetch Sonos group state information
08:57:00.889 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Start notification playback...
08:57:01.260 [TRACE] [os.internal.handler.ZonePlayerHandler] - Received pair 'NewQueueLength':'1' (service 'AVTransport') for thing 'sonos:One:RINCON_48A6B8D0150XXXXXX'
08:57:01.261 [TRACE] [os.internal.handler.ZonePlayerHandler] - Received pair 'FirstTrackNumberEnqueued':'1' (service 'AVTransport') for thing 'sonos:One:RINCON_48A6B8D0150XXXXXX'
08:57:01.261 [TRACE] [os.internal.handler.ZonePlayerHandler] - Received pair 'NumTracksAdded':'1' (service 'AVTransport') for thing 'sonos:One:RINCON_48A6B8D0150XXXXXX'
08:57:01.261 [DEBUG] [os.internal.handler.ZonePlayerHandler] - setCurrentURI URI x-rincon-queue:RINCON_48A6B8D0150XXXXXX#0 URIMetaData 
08:57:01.333 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Notification playback ended
08:57:01.334 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Remove all tracks from queue

The logging level of MaryTTS is Trace, but nothing is logged. I have also tried with Piper with model pre-loading, but nothing gets logged or spoken either.

Others

I deleted OH, installed version 4.3.1, restored the last backup I had (without testing), and upgraded back to 5.2.1, but still the same.

[nelson.aponte]

I just restarted OH and noticed this in the logs:

09:28:21.510 [WARN ] [ce.internal.VoiceManagerConfiguration] - No configuration description found for system:voice, unable to apply defaults!
09:28:29.461 [WARN ] [tty.util.ssl.SslContextFactory.config] - Trusting all certificates configured for Client@3f0e028[provider=null,keyStore=null,trustStore=null]
09:28:29.468 [WARN ] [tty.util.ssl.SslContextFactory.config] - No Client EndPointIdentificationAlgorithm configured for Client@3f0e028[provider=null,keyStore=null,trustStore=null]
09:28:29.519 [WARN ] [tty.util.ssl.SslContextFactory.config] - Trusting all certificates configured for Client@679ebe64[provider=null,keyStore=null,trustStore=null]
09:28:29.525 [WARN ] [tty.util.ssl.SslContextFactory.config] - No Client EndPointIdentificationAlgorithm configured for Client@679ebe64[provider=null,keyStore=null,trustStore=null]
09:28:33.167 [INFO ] [.persistence.jdbc.internal.JdbcMapper] - JDBC::openConnection: Driver is available::Yank setupDataSource
09:28:33.519 [INFO ] [.io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = fa...35, base URL = http://localhost:8080)
09:28:38.830 [INFO ] [.internal.ModuleHandlerFactoryStarter] - WebPushNotificationModuleHandlerFactory started by ModuleHandlerFactoryStarter
09:28:39.206 [INFO ] [nhab.ui.habot.tile.internal.HABotTile] - Started HABot at /habot
09:28:39.254 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : BundleComponentActivator : ComponentHolder created.
09:28:39.262 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Dependency Manager created $000interface=org.openhab.core.voice.TTSCache, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=service, parameter=0
09:28:39.267 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null
09:28:39.273 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Component created: DS=DS14, implementation=org.openhab.voice.marytts.internal.MaryTTSService, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[org.openhab.voice.marytts.internal.MaryTTSService]
09:28:39.279 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Component Services: scope=singleton, services=[org.openhab.core.voice.TTSService]
09:28:39.284 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
09:28:39.289 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Querying state disabled
09:28:39.295 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Querying state disabled
09:28:39.299 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Component can not be activated since it is in state disabled
09:28:39.303 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService] : Querying state disabled
09:28:39.309 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Updating target filters
09:28:39.316 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : No change in target property for dependency $000: currently registered: false
09:28:39.325 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] :  No existing service listener to unregister for dependency $000
09:28:39.330 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Setting target property for dependency $000 to null
09:28:39.335 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.voice.TTSCache), initialReferenceFilter (objectClass=org.openhab.core.voice.TTSCache)
09:28:39.341 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm $000 tracker reset (closed)
09:28:39.347 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.voice.TTSCache}={service.id=518, service.bundleid=228, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), defaultTTS=marytts, component.name=org.openhab.core.voice.internal.cache.TTSLRUCacheImpl, component.id=349, defaultVoice=marytts:cmuslthsmm, felix.fileinstall.filename=file:/var/lib/openhab/etc/org.openhab.voice.cfg, defaultHLI=system, service.pid=org.openhab.voice} (enter)
09:28:39.354 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
09:28:39.360 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.voice.TTSCache}={service.id=518, service.bundleid=228, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), defaultTTS=marytts, component.name=org.openhab.core.voice.internal.cache.TTSLRUCacheImpl, component.id=349, defaultVoice=marytts:cmuslthsmm, felix.fileinstall.filename=file:/var/lib/openhab/etc/org.openhab.voice.cfg, defaultHLI=system, service.pid=org.openhab.voice} (exit)
09:28:39.365 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm $000 tracker opened
09:28:39.368 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : registering service listener for dependency $000
09:28:39.372 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
09:28:39.375 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
09:28:39.379 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
09:28:39.384 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm osgi.ds.satisfying.condition tracker reset (closed)
09:28:39.389 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm osgi.ds.satisfying.condition tracking 2 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
09:28:39.393 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm osgi.ds.satisfying.condition tracking 2 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
09:28:39.399 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : dm osgi.ds.satisfying.condition tracker opened
09:28:39.404 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : registering service listener for dependency osgi.ds.satisfying.condition
09:28:39.409 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Changed state from disabled to unsatisfiedReference
09:28:39.415 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Component enabled
09:28:39.426 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : ActivateInternal
09:28:39.432 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Querying state unsatisfiedReference
09:28:39.437 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Querying state unsatisfiedReference
09:28:39.442 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Activating component from state unsatisfiedReference
09:28:39.446 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Querying state unsatisfiedReference
09:28:39.452 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Querying state unsatisfiedReference
09:28:39.458 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Changed state from unsatisfiedReference to satisfied
09:28:39.463 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : registration change queue [registered]
09:28:39.485 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Checking constructor public org.openhab.voice.marytts.internal.MaryTTSService(org.openhab.core.voice.TTSCache)
09:28:39.490 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.voice.TTSCache through loader of org.openhab.voice.marytts.internal.MaryTTSService
09:28:39.497 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : getClassFromComponentClassLoader: Found class org.openhab.core.voice.TTSCache
09:28:39.505 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Found constructor with 1 arguments : public org.openhab.voice.marytts.internal.MaryTTSService(org.openhab.core.voice.TTSCache)
09:28:39.510 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : This thread collected dependencies
09:28:39.515 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : getService (single component manager) dependencies collected.
09:28:39.519 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Querying state satisfied
09:28:39.524 [TRACE] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : Querying state satisfied
09:28:39.529 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.voice.TTSCache}={service.id=518, service.bundleid=228, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), defaultTTS=marytts, component.name=org.openhab.core.voice.internal.cache.TTSLRUCacheImpl, component.id=349, defaultVoice=marytts:cmuslthsmm, felix.fileinstall.filename=file:/var/lib/openhab/etc/org.openhab.voice.cfg, defaultHLI=system, service.pid=org.openhab.voice}] service: [null]]]
09:28:39.538 [DEBUG] [voice.marytts.internal.MaryTTSService] - bundle org.openhab.voice.marytts:5.2.1 (330)[org.openhab.voice.marytts.internal.MaryTTSService(482)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]

[rlkoshak (Rich Koshak)]

I’m not using Sonos nor MaryTTS. Instead I’m using chromecast and piper.

All I can say is that I know if the Thing I’m sending the audio to is not ONLINE, it crashes the rule. Based on what you describe I’d guess that your Sonos stuff is ONLINE and configured correctly and the problem is somewhere in the voice config or MaryTTS.

Since you have Piper, have you tried using that and does it behave the same?

[nelson.aponte]

I’ve never used Piper before, only Pico, until I migrated from OpenHabian to CENTOS and the required library was not supported. Then I started using Mary.

The Sonos speaker is ONLINE, and when I select Piper instead of Mary as the default TTS, nothing changes.

[rlkoshak (Rich Koshak)]

With Piper you also need to separately download the voices and select the default voice to use.

[nelson.aponte]

I thought I read that it would download the libraries automatically when connected to the internet.

[rlkoshak (Rich Koshak)]

Downloading Voice Model Files

You can find an overview of the available voices on GitHub (opens new window).

Each voice model is composed of two files: an ONNX runtime model file with extension .onnx and a model config file with extension .onnx.json. For the add-on to load your voices, the two files must have the same base filename (differing only in their extensions).

You should place both voice files at ‘<OPENHAB_USERDATA>/piper/’. After that, Main UI should display your available voices at Settings / System Settings / Voice.

Piper Text-to-Speech

[nelson.aponte]

I’ll give it a try tomorrow morning. Thanks for pointing that out, @rlkoshak!

[nelson.aponte]

Update about Sonos: I can finally see the list of favorites and info on what’s playing. I guess it’s safe to discard Sonos as the problem.

So I downloaded one of the voices and uploaded the 2 files to the /var/lib/openhab/piper/ folder, as mentioned in the instructions

[home-automator@localhost piper]$ ls
en_US-amy-medium.onnx  en_US-amy-medium.onnx.json  lib-1.4.2  piper-jni-1.4.2.jar

The piper-jni file was already there. I went to Settings > System Settings → Voice and selected Piper, but it still doesn’t find the voices:

08:49:35.147[DEBUG] [org.openhab.voice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:5.2.1 (332)[org.openhab.voice.pipertts.internal.PiperTTSService(483)] : dm $000 tracking 4 SingleStatic modified {org.openhab.core.voice.TTSCache}={service.id=518, service.bundleid=228, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), felix.fileinstall.filename=file:/var/lib/openhab/etc/org.openhab.voice.cfg, defaultTTS=marytts, defaultHLI=system, service.pid=org.openhab.voice, component.name=org.openhab.core.voice.internal.cache.TTSLRUCacheImpl, component.id=349} (enter)
08:49:35.149[DEBUG] [org.openhab.voice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:5.2.1 (332)[org.openhab.voice.pipertts.internal.PiperTTSService(483)] : dm $000 tracking 4 SingleStatic modified {org.openhab.core.voice.TTSCache}={service.id=518, service.bundleid=228, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), felix.fileinstall.filename=file:/var/lib/openhab/etc/org.openhab.voice.cfg, defaultTTS=marytts, defaultHLI=system, service.pid=org.openhab.voice, component.name=org.openhab.core.voice.internal.cache.TTSLRUCacheImpl, component.id=349} (exit)
08:49:35.159[DEBUG] [org.openhab.voice.pipertts.internal.PiperTTSService] - Available number of piper voices: 0

[rlkoshak (Rich Koshak)]

OK, since it seems to fail for two tts add-ons it has to be something about the voice system overall and not the tts add-on. There could be something wrong with the Sonos add-on itself with what is happening in the audio transmission.

Can you send it an MP3 or WAV file from a rule?

[JustinG]

FWIW: I use Mimic for TTS and I successfully send voice notifications to my Sonos speakers using voice actions in rules regularly (5.3 snapshot).

(And just based on the fact that I still use Mimic you can correctly intuit that this has been stable for quite a few years.)

[rlkoshak (Rich Koshak)]

I’m successfully using Piper with Chromecasts too. But there is something unique going wrong with @nelson.aponte’s setup I can’t quite pinpoint.

My experience with Voice in OH is really limited. I’m not even sure what loggers to change to debug. Definitely open to new ideas. I’m not even sure where to file an issue at this point.

[JustinG]

The only issues I ever had with the sonos binding all relate to the fact that I run OH in a docker container and docker doesn’t play well with jupnp so there’s a lot of massaging of extra jupnp settings to get everything to talk to each other. That shouldn’t be a problem just running on an rPI. That said, the unidirectional communication (oh → sonos OK, but sonos → oh not), looks a lot like some of those jupnp symptoms.

Do you have more than one network interface on that rPI? That’s one of the thing that trips up sonos’s jupnp connections.

[Lolodomo]

Piper TTS + Sonos still working well for me in 5.2.1.

[nelson.aponte]

@nelson.aponte

I just restarted OH and noticed this in the logs:

Does this warning ring any bells?

09:28:21.510 [WARN ] [ce.internal.VoiceManagerConfiguration] - No configuration description found for system:voice, unable to apply defaults!

I found it after a system restart, when Mary was set as the default TTS, together with its default voice configuration, just like I’d used it for years.

@JustinG

Do you have more than one network interface on that rPI? That’s one of the thing that trips up sonos’s jupnp connections.

@JustinG, no, it’s connected via an Ethernet cable only.

@Lolodomo

Piper TTS + Sonos still working well for me in 5.2.1.

@Lolodomo, have you done anything different than what I did to configure Piper? I have a manual OH installation.

[Lolodomo]

@nelson.aponte

@Lolodomo, have you done anything different than what I did to configure Piper? I have a manual OH installation.

I switch to Piper TTS few months ago and I don’t remember exactly what I did. I just followed instructions in README. If I correctly remember, I choose a voice (from a WEB site) and finally download and setup it in OH.
I don’t remember it was really difficult.

The most difficult was to choose the voice

[nelson.aponte]

@rlkoshak

Can you send it an MP3 or WAV file from a rule?

@rlkoshak, I created a test rule on Main UI

The rule plays; it doesn’t produce any error; nothing is played on the speaker either, and no error gets logged; then the speaker plays back whatever it was playing before.

09:01:37.122[INFO] [openhab.event.RuleUpdatedEvent] - Rule 'test2' has been updated.
09:05:05.733[DEBUG] [org.openhab.binding.sonos.internal.SonosAudioSink] - Audio stream accessible through HTTP served at /audio/796a11ee-XXXX-XXXX-XXXX-XXXXXXXXXXXX for Sonos playback
09:05:05.734[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - playNotificationSoundURI: notificationURL http://10.18.18.124:8080/audio/796a11ee-XXXX-XXXX-XXXX-XXXXXXXXXXXX.mp3 currentURI x-sonos-vli:RINCON_48A6B8D01XXXXXXXX:2,spotify:d2b6a8d78fa3558150335cbd595c7c42 metadata <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="spotify" parentID="0" restricted="false"><dc:title>Spotify</dc:title><upnp:class>object.item.audioItem.linein</upnp:class><res protocolInfo="x-sonos-vli:*:audio:*">x-sonos-vli:RINCON_48A6B8D01XXXXXXXX:2,spotify:d2b6a8d78fa3558150335cbd595c7c42</res><vli cookie="10" group=""></vli></item></DIDL-Lite>
09:05:05.735[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Handling notification while virtual line-in is playing or last played
09:05:05.736[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - handleNotificationSound: URL http://10.XX.XX.XXX:8080/audio/796a11ee-XXXX-XXXX-XXXX-XXXXXXXXXXXX.mp3 coordinator RINCON_48A6B8D01XXXXXXXX
09:05:05.738[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Stop current playback...
09:05:05.746[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Current playback stopped
09:05:05.747[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Apply notification volume
09:05:05.760[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Add notification URI http://10.XX.XX.XXX:8080/audio/796a11ee-XXXX-XXXX-XXXX-XXXXXXXXXXXX.mp3 to queue
09:05:05.768[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Set current URI to x-rincon-queue:RINCON_48A6B8D01XXXXXXXX#0
09:05:05.769[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - setCurrentURI URI x-rincon-queue:RINCON_48A6B8D01XXXXXXXX#0 URIMetaData
09:05:05.842[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Set track position to 1
09:05:05.849[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Start notification playback...
09:05:14.460[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Polling job
09:05:25.938[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Notification playback ended
09:05:25.940[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Restore original volume 30
09:05:25.956[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Remove notification track from queue
09:05:25.964[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Restoring sound from virtual line-in using URI x-sonos-vli:RINCON_48A6B8D01XXXXXXXX:2,spotify:d2b6a8d78fa3558150335cbd595c7c42 and metadata <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="spotify" parentID="0" restricted="false"><dc:title>Spotify</dc:title><upnp:class>object.item.audioItem.linein</upnp:class><res protocolInfo="x-sonos-vli:*:audio:*">x-sonos-vli:RINCON_48A6B8D01XXXXXXXX:2,spotify:d2b6a8d78fa3558150335cbd595c7c42</res><vli cookie="10" group=""></vli></item></DIDL-Lite>
09:05:25.964[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - setCurrentURI URI x-sonos-vli:RINCON_48A6B8D01XXXXXXXX:2,spotify:d2b6a8d78fa3558150335cbd595c7c42 URIMetaData <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="spotify" parentID="0" restricted="false"><dc:title>Spotify</dc:title><upnp:class>object.item.audioItem.linein</upnp:class><res protocolInfo="x-sonos-vli:*:audio:*">x-sonos-vli:RINCON_48A6B8D01XXXXXXXX:2,spotify:d2b6a8d78fa3558150335cbd595c7c42</res><vli cookie="10" group=""></vli></item></DIDL-Lite>
09:06:14.472[DEBUG] [org.openhab.binding.sonos.internal.handler.ZonePlayerHandler] - Polling job

I found it strange that the filename is provided as a GUID and not the actual name

- handleNotificationSound: URL http://10.XX.XX.XXX:8080/audio/796a11ee-XXXX-XXXX-XXXX-XXXXXXXXXXXX.mp3

By the way, as I mentioned before, I can play channels on the speaker from OH (both the UI controls and rules).

And still, I can’t see the uploaded voices for Piper

Even though the files are in the folder mentioned in the documentation:

[home-automator@localhost ~]$ cd /var/lib/openhab/piper/
[home-automator@localhost piper]$ ls -l
total 173512
-rw-r--r--. 1 openhab openhab 63201294 Aug 31 15:23 en_US-amy-medium.onnx
-rw-r--r--. 1 openhab openhab 63201294 Aug 31 15:23 en_US-amy-medium.onnx.json
drwxrwxr-x. 3 openhab openhab     4096 Aug 23 12:42 lib-1.4.2
-rwxrwxr-x. 1 openhab openhab 51248147 Aug 23 12:42 piper-jni-1.4.2.jar
[home-automator@localhost piper]$ 

I’ve set the org.openhab.voice.piper logger to TRACE, but all it logs is

09:30:03.136[DEBUG] [org.openhab.voice.pipertts.internal.PiperTTSService] - Available number of piper voices: 0

[rlkoshak (Rich Koshak)]

@nelson.aponte

Available number of piper voices: 0

Unless and until that line says something more than 1 piper isn’t going to work. But it’s not clear why it wouldn’t work. Everything looks correct and I have no ideas. When I followed the instructions it just worked. I have no actual debugging experience with the voice subsystem. The fact that neither MaryTTS nor Piper work might be meaningful, might not be.