openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.9k stars 3.59k forks source link

[pipertts] Add-on is not loaded error when calling 'say' action #17700

Open Procsiab opened 1 week ago

Procsiab commented 1 week ago

Expected Behavior

The following command should result in the text message to be spoken out by the configured audio sink:

openhab:voice say Test

Current Behavior

The message is not spoken out and the following error appears on the logs:

18:00:33.292 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Available number of piper voices: 1
18:00:33.294 [WARN ] [.core.voice.internal.VoiceManagerImpl] - Error saying 'Test ': Add-on is not loaded

I am using the org.openhab.voice.pipertts binding on OpenHAB 4.2.2-alpine container variant. I installed the binding through the UI from the section Add-on store.

I tried to use two different audio sinks but the behaviour is the same:

(NOTE: the PC which OpenHAB runs on has no builtin speakers)

I tried to restart OpenHAB after installing the binding and after cleaning the cache and tmp folders under the userdata volume.

I tried to restart the binding after OpenHAB was fully loaded up.

The PiperTTS binding appears inside the UI "Add-on Settings" section, where I can also change successfully its logging level.

The following log at trace level is what is printed for pipertts while it is being loaded:

startup.log ``` 17:55:48.998 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : BundleComponentActivator : ComponentHolder created. 17:55:48.999 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : ConfigurableComponentHolder configuration updated for pid org.openhab.voice.pipertts with change count 7 17:55:49.000 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : 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 17:55:49.001 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, car dinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null 17:55:49.001 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : Component created: DS=DS14, implementation=org.openhab.voice.pipertts.internal.PiperTTSService, immediate=false, default-enabled=true, factory=null, config uration-policy=optional, activate=activate, deactivate=deactivate, modified=modified configuration-pid=[org.openhab.voice.pipertts] 17:55:49.002 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : Component Services: scope=singleton, services=[org.openhab.core.voice.TTSService] 17:55:49.002 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : Component Properties: {service.config.label=Piper Text-to-Speech, service.config.category=voice, osgi.ds.satisfying.condition.target=(osgi.condition.id=tru e), service.config.description.uri=voice:pipertts, service.config.factory=false, service.pid=org.openhab.voice.pipertts} 17:55:49.003 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : Querying state disabled 17:55:49.003 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : Querying state disabled 17:55:49.004 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : Component can not be activated since it is in state disabled 17:55:49.004 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService] : Querying state disabled 17:55:49.005 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Updating target filters 17:55:49.006 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : No change in target property for dependency $000: currently registered: false 17:55:49.006 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : No existing service listener to unregister for dependency $000 17:55:49.007 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Setting target property for dependency $000 to null 17:55:49.007 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.voice.TTSCache), initialRefer enceFilter (objectClass=org.openhab.core.voice.TTSCache) 17:55:49.008 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : dm $000 tracker reset (closed) 17:55:49.010 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.voice.TTSCache}={service.id=1009, service.bundleid=225, service.scope=bundle, osgi.ds.satisfyi ng.condition.target=(osgi.condition.id=true), defaultTTS=pipertts, component.name=org.openhab.core.voice.internal.cache.TTSLRUCacheImpl, component.id=312, defaultVoice=pipertts:paola-it_IT, felix.fileinstall.filename=file:/openhab/userdata/etc/org.openhab.voice.cfg, defaultHLI=rulehli, service.pid=org.openhab.voice, e nableCacheTTS=false} (enter) 17:55:49.012 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false 17:55:49.013 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.voice.TTSCache}={service.id=1009, service.bundleid=225, service.scope=bundle, osgi.ds.satisfyi ng.condition.target=(osgi.condition.id=true), defaultTTS=pipertts, component.name=org.openhab.core.voice.internal.cache.TTSLRUCacheImpl, component.id=312, defaultVoice=pipertts:paola-it_IT, felix.fileinstall.filename=file:/openhab/userdata/etc/org.openhab.voice.cfg, defaultHLI=rulehli, service.pid=org.openhab.voice, e nableCacheTTS=false} (exit) 17:55:49.014 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : dm $000 tracker opened 17:55:49.015 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : registering service listener for dependency $000 17:55:49.015 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : No existing service listener to unregister for dependency osgi.ds.satisfying.condition 17:55:49.016 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true) 17:55:49.017 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condi tion.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true)) 17:55:49.018 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : dm osgi.ds.satisfying.condition tracker reset (closed) 17:55:49.019 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : 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) 17:55:49.020 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : 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) 17:55:49.021 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : dm osgi.ds.satisfying.condition tracker opened 17:55:49.022 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : registering service listener for dependency osgi.ds.satisfying.condition 17:55:49.022 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Changed state from disabled to unsatisfiedReference 17:55:49.023 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Component enabled 17:55:49.024 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : ActivateInternal 17:55:49.025 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Querying state unsatisfiedReference 17:55:49.026 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Querying state unsatisfiedReference 17:55:49.027 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Activating component from state unsatisfiedReference 17:55:49.027 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Querying state unsatisfiedReference 17:55:49.028 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Querying state unsatisfiedReference 17:55:49.029 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Changed state from unsatisfiedReference to satisfied 17:55:49.030 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : registration change queue [registered] 17:55:49.031 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Checking constructor public org.openhab.voice.pipertts.internal.PiperTTSService(org.openhab.core.voice.TTSCache) 17:55:49.032 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.voice.TTSCache through loader of org.openhab.voice.pipertts.internal.Pi perTTSService 17:55:49.033 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : getClassFromComponentClassLoader: Found class org.openhab.core.voice.TTSCache 17:55:49.033 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Found constructor with 1 arguments : public org.openhab.voice.pipertts.internal.PiperTTSService(org.openhab.core.voice.TTSCache) 17:55:49.034 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : This thread collected dependencies 17:55:49.035 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : getService (single component manager) dependencies collected. 17:55:49.035 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Querying state satisfied 17:55:49.036 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Querying state satisfied 17:55:49.036 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.voice.TTSCache}={service.id=1009, service.bundleid=225, service.scop e=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), defaultTTS=pipertts, component.name=org.openhab.core.voice.internal.cache.TTSLRUCacheImpl, component.id=312, defaultVoice=pipertts:paola-it_IT, felix.fileinstall.filename=file:/openhab/userdata/etc/org.openhab.voice.cfg, defaultHLI=rulehli, servic e.pid=org.openhab.voice, enableCacheTTS=false}] service: [null]]] 17:55:49.037 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : 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]]] 17:55:49.038 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : getting activate: activate 17:55:49.038 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Locating method activate in class org.openhab.voice.pipertts.internal.PiperTTSService 17:55:49.039 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Declared Method org.openhab.voice.pipertts.internal.PiperTTSService.activate([interface org.osgi.service.component.ComponentContext]) not found 17:55:49.039 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Found activate method: protected void org.openhab.voice.pipertts.internal.PiperTTSService.activate(java.util.Map) 17:55:49.040 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.helper.ReadOnlyDictionary] 17:55:49.040 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : invoked activate: activate 17:55:49.041 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: debian-amd64/ 17:55:49.042 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: debian-amd64/libpiper_phonemize.so.1 17:55:49.042 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Set implementation object for component 17:55:49.043 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: debian-amd64/.gitkeep 17:55:49.044 [DEBUG] [ice.pipertts.internal.PiperTTSService] - bundle org.openhab.voice.pipertts:4.2.2 (319)[org.openhab.voice.pipertts.internal.PiperTTSService(416)] : Changed state from satisfied to active 17:55:49.045 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: debian-amd64/libespeak-ng.so.1.52.0.1 17:55:49.049 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: debian-amd64/libpiper-jni.so 17:55:49.051 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: debian-amd64/libespeak-ng.so.1 17:55:49.053 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: espeak-ng-data.zip 17:55:49.054 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: debian-amd64/libpiper_phonemize.so.1.2.0 17:55:49.059 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: debian-amd64/libonnxruntime.so.1.14.1 17:55:49.060 [DEBUG] [ice.pipertts.internal.PiperTTSService] - Found piper native dependency: libtashkeel_model.ort ```

Possible Solution

If my configuration is not supported or I am missing something, I propose to make this clearer in the binding's documentation. If this is a bug, I really don't know where to go from here to find the cause and propose a solution.

Steps to Reproduce (for Bugs)

  1. Install Fedora IoT stable/x86_64 40.20240918.0
  2. Use Podman 5.2.2 (bundled with the OS) to start a container instance from the image docker.io/openhab/openhab:4.2.2-alpine
  3. Install PiperTTS through the UI
  4. Configure an Audio sink and the Voice settings from the UI settings
  5. Try to run the command or the ECMA Script action say with any message

Context

I am trying to make OpenHAB play an audio transcription of a fixed text message on a Google Home Mini speaker.

Your Environment

CyborgAscendant commented 2 days ago

I am also experiencing this issue, but on Windows 11, OpenHAB 4.2.2, and using Google Chrome to interact with OpenHAB. Apart from that my experience is identical (through the UI, using Google speakers but tried Web Audio sink, same error message).