openhab-addons: [yamahareceiver] high CPU usage bursts after adding zone things (RX-A3020)

My environment: openhab 2.5.2 Release Build, x64 platform, Ubuntu Server 18.04 LTS 286 │ Active │ 80 │ 2.5.2 │ openHAB Add-ons :: Bundles :: Yamaha Receiver Binding

This issue is 100% reproducible using my Yamaha RX-A3020 (fw 1.98) wired Eth LAN. After installing this item, all is fine, CPU usage is normal 5-6% watched over a period of several minutes. :

After installing MAIN Zone, CPU usage spikes to 100-150% for 5-10s every 30s.

This is the trace log from 2 such periods. Note how the log entries only last for some 150ms out of the 5-10s period:

    2020-03-15 18:53:33.722 [TRACE] [internal.handler.YamahaBridgeHandler] - updateAllZoneInformation
    2020-03-15 18:53:33.723 [DEBUG] [.internal.protocol.xml.XMLConnection] - Making POST to http://192.168.1.107:80/YamahaRemoteControl/ctrl with payload: <?xml version="1.0" encoding="utf-8"?><YAMAHA_AV cmd="GET"><System><Power_Control><Power>GetParam</Power></Power_Control></System></YAMAHA_AV>
    2020-03-15 18:53:33.752 [TRACE] [.internal.protocol.xml.XMLConnection] - The charset UTF-8 will be used to parse the response
    2020-03-15 18:53:33.765 [DEBUG] [.internal.protocol.xml.XMLConnection] - Making POST to http://192.168.1.107:80/YamahaRemoteControl/ctrl with payload: <?xml version="1.0" encoding="utf-8"?><YAMAHA_AV cmd="GET"><System><Party_Mode><Mode>GetParam</Mode></Party_Mode></System></YAMAHA_AV>
    2020-03-15 18:53:33.788 [TRACE] [.internal.protocol.xml.XMLConnection] - The charset UTF-8 will be used to parse the response
    2020-03-15 18:53:33.800 [DEBUG] [ternal.protocol.xml.SystemControlXML] - System state - power: true, partyMode: false
    2020-03-15 18:53:33.801 [DEBUG] [.internal.protocol.xml.XMLConnection] - Making POST to http://192.168.1.107:80/YamahaRemoteControl/ctrl with payload: <?xml version="1.0" encoding="utf-8"?><YAMAHA_AV cmd="GET"><Main_Zone><Input><Input_Sel_Item>GetParam</Input_Sel_Item></Input></Main_Zone></YAMAHA_AV>
    2020-03-15 18:53:33.802 [DEBUG] [.internal.protocol.xml.XMLConnection] - Making POST to http://192.168.1.107:80/YamahaRemoteControl/ctrl with payload: <?xml version="1.0" encoding="utf-8"?><YAMAHA_AV cmd="GET"><Main_Zone><Basic_Status>GetParam</Basic_Status></Main_Zone></YAMAHA_AV>
    2020-03-15 18:53:33.837 [TRACE] [.internal.protocol.xml.XMLConnection] - The charset UTF-8 will be used to parse the response
    2020-03-15 18:53:33.856 [TRACE] [rnal.protocol.xml.XMLProtocolService] - Zone Main_Zone - inputs: Napster:RW, NET RADIO:RW, SERVER:RW, AirPlay:RW, USB:RW, iPod (USB):R, TUNER:RW, AV1:RW, AV2:RW, AV3:RW, AV4:RW, AV5:RW, AV6:RW, AV7:RW, AUDIO1:RW, AUDIO2:RW, AUDIO3:RW, AUDIO4:RW, PHONO:RW, V-AUX:RW, MULTI CH:RW
    2020-03-15 18:53:33.857 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name Napster to NAPSTER - as per legacy mapping
    2020-03-15 18:53:33.858 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name NET RADIO to NET RADIO - as per no conversion rule
    2020-03-15 18:53:33.859 [TRACE] [.internal.protocol.xml.XMLConnection] - The charset UTF-8 will be used to parse the response
    2020-03-15 18:53:33.859 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name SERVER to SERVER - as per legacy mapping
    2020-03-15 18:53:33.860 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AirPlay to AIRPLAY - as per legacy mapping
    2020-03-15 18:53:33.861 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name USB to USB - as per legacy mapping
    2020-03-15 18:53:33.861 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name TUNER to TUNER - as per legacy mapping
    2020-03-15 18:53:33.862 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV1 to AV1 - as per legacy mapping
    2020-03-15 18:53:33.863 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV2 to AV2 - as per legacy mapping
    2020-03-15 18:53:33.864 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV3 to AV3 - as per legacy mapping
    2020-03-15 18:53:33.864 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV4 to AV4 - as per legacy mapping
    2020-03-15 18:53:33.865 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV5 to AV5 - as per legacy mapping
    2020-03-15 18:53:33.866 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV6 to AV6 - as per legacy mapping
    2020-03-15 18:53:33.866 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV7 to AV7 - as per legacy mapping
    2020-03-15 18:53:33.867 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO1 to AUDIO1 - as per no conversion rule
    2020-03-15 18:53:33.868 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO2 to AUDIO2 - as per no conversion rule
    2020-03-15 18:53:33.868 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO3 to AUDIO3 - as per no conversion rule
    2020-03-15 18:53:33.869 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO4 to AUDIO4 - as per no conversion rule
    2020-03-15 18:53:33.869 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name PHONO to PHONO - as per legacy mapping
    2020-03-15 18:53:33.870 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name V-AUX to V-AUX - as per legacy mapping
    2020-03-15 18:53:33.870 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name MULTI CH to MULTI_CH - as per legacy mapping
    2020-03-15 18:53:33.871 [TRACE] [.protocol.xml.ZoneAvailableInputsXML] - Zone Main_Zone - available inputs: AIRPLAY, AUDIO1, AUDIO2, AUDIO3, AUDIO4, AV1, AV2, AV3, AV4, AV5, AV6, AV7, MULTI_CH, NAPSTER, NET RADIO, PHONO, SERVER, TUNER, USB, V-AUX
    2020-03-15 18:53:33.877 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO1 to AUDIO1 - as per no conversion rule
    2020-03-15 18:53:33.878 [DEBUG] [internal.protocol.xml.ZoneControlXML] - Zone Main_Zone state - power: true, mute: false, volumeDB: -46.5, input: AUDIO1, surroundProgram: Surround Decoder
    2020-03-15 18:54:03.272 [INFO ] [e.smarthome.model.script.SmokeAlarms] - Changed: Smokealarms=OFF
    2020-03-15 18:54:03.273 [INFO ] [.model.script.UniversalBinarySensor2] - Update: UniversalBinarySensor2=OFF




    2020-03-15 18:54:11.048 [WARN ] [.ZWaveThermostatSetpointCommandClass] - Reached max tries to init the setpont Furnace, this will be our last attempt
    2020-03-15 18:54:12.646 [INFO ] [smarthome.model.script.HVAC:Setpoint] - HVACVindfangsetPoint=22.5 °C



    2020-03-15 18:54:33.802 [TRACE] [internal.handler.YamahaBridgeHandler] - updateAllZoneInformation
    2020-03-15 18:54:33.803 [DEBUG] [.internal.protocol.xml.XMLConnection] - Making POST to http://192.168.1.107:80/YamahaRemoteControl/ctrl with payload: <?xml version="1.0" encoding="utf-8"?><YAMAHA_AV cmd="GET"><System><Power_Control><Power>GetParam</Power></Power_Control></System></YAMAHA_AV>
    2020-03-15 18:54:33.832 [TRACE] [.internal.protocol.xml.XMLConnection] - The charset UTF-8 will be used to parse the response
    2020-03-15 18:54:33.845 [DEBUG] [.internal.protocol.xml.XMLConnection] - Making POST to http://192.168.1.107:80/YamahaRemoteControl/ctrl with payload: <?xml version="1.0" encoding="utf-8"?><YAMAHA_AV cmd="GET"><System><Party_Mode><Mode>GetParam</Mode></Party_Mode></System></YAMAHA_AV>
    2020-03-15 18:54:33.868 [TRACE] [.internal.protocol.xml.XMLConnection] - The charset UTF-8 will be used to parse the response
    2020-03-15 18:54:33.881 [DEBUG] [ternal.protocol.xml.SystemControlXML] - System state - power: true, partyMode: false
    2020-03-15 18:54:33.882 [DEBUG] [.internal.protocol.xml.XMLConnection] - Making POST to http://192.168.1.107:80/YamahaRemoteControl/ctrl with payload: <?xml version="1.0" encoding="utf-8"?><YAMAHA_AV cmd="GET"><Main_Zone><Input><Input_Sel_Item>GetParam</Input_Sel_Item></Input></Main_Zone></YAMAHA_AV>
    2020-03-15 18:54:33.886 [DEBUG] [.internal.protocol.xml.XMLConnection] - Making POST to http://192.168.1.107:80/YamahaRemoteControl/ctrl with payload: <?xml version="1.0" encoding="utf-8"?><YAMAHA_AV cmd="GET"><Main_Zone><Basic_Status>GetParam</Basic_Status></Main_Zone></YAMAHA_AV>
    2020-03-15 18:54:33.924 [TRACE] [.internal.protocol.xml.XMLConnection] - The charset UTF-8 will be used to parse the response
    2020-03-15 18:54:33.930 [TRACE] [.internal.protocol.xml.XMLConnection] - The charset UTF-8 will be used to parse the response
    2020-03-15 18:54:33.942 [TRACE] [rnal.protocol.xml.XMLProtocolService] - Zone Main_Zone - inputs: Napster:RW, NET RADIO:RW, SERVER:RW, AirPlay:RW, USB:RW, iPod (USB):R, TUNER:RW, AV1:RW, AV2:RW, AV3:RW, AV4:RW, AV5:RW, AV6:RW, AV7:RW, AUDIO1:RW, AUDIO2:RW, AUDIO3:RW, AUDIO4:RW, PHONO:RW, V-AUX:RW, MULTI CH:RW
    2020-03-15 18:54:33.943 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name Napster to NAPSTER - as per legacy mapping
    2020-03-15 18:54:33.944 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name NET RADIO to NET RADIO - as per no conversion rule
    2020-03-15 18:54:33.944 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name SERVER to SERVER - as per legacy mapping
    2020-03-15 18:54:33.945 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AirPlay to AIRPLAY - as per legacy mapping
    2020-03-15 18:54:33.945 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name USB to USB - as per legacy mapping
    2020-03-15 18:54:33.946 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name TUNER to TUNER - as per legacy mapping
    2020-03-15 18:54:33.946 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV1 to AV1 - as per legacy mapping
    2020-03-15 18:54:33.947 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV2 to AV2 - as per legacy mapping
    2020-03-15 18:54:33.948 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV3 to AV3 - as per legacy mapping
    2020-03-15 18:54:33.948 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV4 to AV4 - as per legacy mapping
    2020-03-15 18:54:33.949 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV5 to AV5 - as per legacy mapping
    2020-03-15 18:54:33.949 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV6 to AV6 - as per legacy mapping
    2020-03-15 18:54:33.950 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AV7 to AV7 - as per legacy mapping
    2020-03-15 18:54:33.951 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO1 to AUDIO1 - as per no conversion rule
    2020-03-15 18:54:33.951 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO2 to AUDIO2 - as per no conversion rule
    2020-03-15 18:54:33.951 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO1 to AUDIO1 - as per no conversion rule
    2020-03-15 18:54:33.953 [DEBUG] [internal.protocol.xml.ZoneControlXML] - Zone Main_Zone state - power: true, mute: false, volumeDB: -46.5, input: AUDIO1, surroundProgram: Surround Decoder
    2020-03-15 18:54:33.951 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO3 to AUDIO3 - as per no conversion rule
    2020-03-15 18:54:33.955 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name AUDIO4 to AUDIO4 - as per no conversion rule
    2020-03-15 18:54:33.955 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name PHONO to PHONO - as per legacy mapping
    2020-03-15 18:54:33.956 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name V-AUX to V-AUX - as per legacy mapping
    2020-03-15 18:54:33.956 [TRACE] [ernal.protocol.xml.InputConverterXML] - Converting from state name MULTI CH to MULTI_CH - as per legacy mapping
    2020-03-15 18:54:33.957 [TRACE] [.protocol.xml.ZoneAvailableInputsXML] - Zone Main_Zone - available inputs: AIRPLAY, AUDIO1, AUDIO2, AUDIO3, AUDIO4, AV1, AV2, AV3, AV4, AV5, AV6, AV7, MULTI_CH, NAPSTER, NET RADIO, PHONO, SERVER, TUNER, USB, V-AUX

Adding more Zone things, Zone2,3,4 the issue gets worse, flattening out on a continuous CPU usage of 180%. After deleting all zone things, CPU usage is back to normal.

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 15 (15 by maintainers)

Commits related to this issue

Avoid async calls when updating the zone information Potential fix for #7184 Signed-off-by: Laurent Garnier <lg.hc@free.fr> — committed to lolodomo/openhab-addons by lolodomo 4 years ago
Avoid async calls when updating the zone information Potential fix for #7184 Signed-off-by: Laurent Garnier <lg.hc@free.fr> — committed to lolodomo/openhab-addons by lolodomo 4 years ago
Avoid async calls when updating the zone information Potential fix for #7184 Signed-off-by: Laurent Garnier <lg.hc@free.fr> — committed to lolodomo/openhab-addons by lolodomo 4 years ago
Avoid multiple async calls when updating the zone information Potential fix for #7184 Signed-off-by: Laurent Garnier <lg.hc@free.fr> — committed to lolodomo/openhab-addons by lolodomo 4 years ago
Avoid multiple async calls when updating the zone information Potential fix for #7184 Signed-off-by: Laurent Garnier <lg.hc@free.fr> — committed to lolodomo/openhab-addons by lolodomo 4 years ago
[yamahareceiver] Avoid multiple async calls when updating the zone information Potential fix for #7184 Signed-off-by: Laurent Garnier <lg.hc@free.fr> — committed to lolodomo/openhab-addons by lolodomo 4 years ago

Most upvoted comments

Ok, thank you for the test, I will close my proposal in this case.

lolodomo on Jun 3, 2020

I proposed a fix that avoids starting multiplke commands in parallel in different threads (the used thrread pool has a very limioted size).

lolodomo on May 20, 2020