[SOLVED] Jython startup issue loading core modules

scottk · May 11, 2020, 3:38am

Platform information:
- Hardware: Intel Core i5-4570/32 GiB RAM/512 GB SSD/CentOS 7 current
- Java Runtime Environment: Docker image: 2.5.5-snapshot-amd64-debian
- openHAB version: 2.5.5-SNAPSHOT Build #108

Up to this evening my OH2 system had been quite stable running OH 2.5.4-SNAPSHOT Build #78. I stopped docker to update some thing and item files and restarted the system. No errors from the updated thing and item files were reported, but the NGRE failed upon loading the various python modules from automation/jsr223/python/core. I have verified multiple times that everything in my openhab_conf volume is unchanged (I keep a copy in a local git repository.)

I first tried stopping OH, clearing tmp/* and cache/*, then restarted OH – no joy. I tried stopping OH, deleting all files matching *class under openhab_conf/, then restarted OH – still got the errors.

I then thought I would try the latest 2.5.x snapshot (I still have the Docker 2.5.4-SNAPSHOT Build #78, so I can easily revert to that), but I still get the jython core load errors.

Relevant part of openhab log:

2020-05-10 21:13:48.924 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'javascript/core/000_startup_delay.js'
2020-05-10 21:13:50.827 [DEBUG][-thingHandler-3][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.207:3000
2020-05-10 21:13:50.827 [DEBUG][-thingHandler-2][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.208:3000
2020-05-10 21:13:51.827 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:13:51.827 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:00.827 [DEBUG][-thingHandler-2][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.207:3000
2020-05-10 21:14:00.827 [DEBUG][-thingHandler-1][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.208:3000
2020-05-10 21:14:01.828 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:01.828 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:10.828 [DEBUG][-thingHandler-2][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.208:3000
2020-05-10 21:14:10.828 [DEBUG][-thingHandler-5][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.207:3000
2020-05-10 21:14:11.828 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:11.829 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:19.248 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/000_startup_delay.py'
2020-05-10 21:14:20.828 [DEBUG][-thingHandler-1][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.207:3000
2020-05-10 21:14:20.828 [DEBUG][-thingHandler-5][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.208:3000
2020-05-10 21:14:21.829 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:21.829 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:30.829 [DEBUG][-thingHandler-5][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.208:3000
2020-05-10 21:14:30.829 [DEBUG][-thingHandler-2][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.207:3000
2020-05-10 21:14:31.829 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:31.830 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:40.829 [DEBUG][-thingHandler-5][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.207:3000
2020-05-10 21:14:40.829 [DEBUG][-thingHandler-3][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.208:3000
2020-05-10 21:14:41.830 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:41.830 [DEBUG][905b6-scheduler][bos.internal.handler.LGWebOSTVSocket] - setState new DISCONNECTED - current DISCONNECTED
2020-05-10 21:14:49.273 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/100_DirectoryTrigger.py'
2020-05-10 21:14:49.943 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/100_OsgiEventTrigger.py'
2020-05-10 21:14:50.122 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/100_StartupTrigger.py'
2020-05-10 21:14:50.146 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonBindingInfoProvider.py'
2020-05-10 21:14:50.190 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonExtensionProvider.py'
2020-05-10 21:14:50.221 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonItemChannelLinkProvider.py'
2020-05-10 21:14:50.252 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonItemProvider.py'
2020-05-10 21:14:50.277 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonThingProvider.py'
2020-05-10 21:14:50.307 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonThingTypeProvider.py'
2020-05-10 21:14:50.337 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonTransform.py'
2020-05-10 21:14:50.362 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/aaa_keypad-scenes.py'
2020-05-10 21:14:50.771 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/av-activity.py'
2020-05-10 21:14:50.802 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/coat-closet-lights-handler.py'
2020-05-10 21:14:50.819 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/doorbell.py'
2020-05-10 21:14:50.830 [DEBUG][-thingHandler-2][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.207:3000
2020-05-10 21:14:50.830 [DEBUG][-thingHandler-3][bos.internal.handler.LGWebOSTVSocket] - Connecting to: ws://192.168.1.208:3000
2020-05-10 21:14:50.837 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/fans-delayed-off.py'
2020-05-10 21:14:50.859 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/hot-water-recirc-pump.py'
2020-05-10 21:14:50.878 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/kitchen-pendant-handler.py'
2020-05-10 21:14:50.901 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/scheduled-lights.py'
2020-05-10 21:14:50.921 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/community/update_mode/update_mode.py'
2020-05-10 21:14:50.949 [INFO ][ool-20-thread-1][me.core.service.AbstractWatchService] - Loading script 'python/personal/zzz_motion-lights.py'

jsr223 log:

2020-05-10 21:13:19.590 [DEBUG][aa-47656b127774][ntime.internal.engine.RuleEngineImpl] - Started rule engine
2020-05-10 21:13:49.224 [INFO ][ool-20-thread-1][jsr223.javascript.core.startup_delay] - Checking for initialized context
2020-05-10 21:13:49.237 [INFO ][ool-20-thread-1][jsr223.javascript.core.startup_delay] - Context initialized... waiting 30s before allowing scripts to load
2020-05-10 21:14:19.247 [INFO ][ool-20-thread-1][jsr223.javascript.core.startup_delay] - Complete
2020-05-10 21:14:19.272 [INFO ][ool-20-thread-1][jsr223.jython.core.startup_delay    ] - Checking for initialized context
2020-05-10 21:14:19.273 [INFO ][ool-20-thread-1][jsr223.jython.core.startup_delay    ] - Context initialized... waiting 30s before allowing scripts to load
2020-05-10 21:14:49.273 [INFO ][ool-20-thread-1][jsr223.jython.core.startup_delay    ] - Complete
2020-05-10 21:14:49.943 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py': TypeError: 'tuple' object is not callable in <script> at line number 21
2020-05-10 21:14:50.122 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py': TypeError: 'tuple' object is not callable in <script> at line number 17
2020-05-10 21:14:50.145 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/100_StartupTrigger.py': TypeError: 'tuple' object is not callable in <script> at line number 16
2020-05-10 21:14:50.190 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py': TypeError: 'tuple' object is not callable in <script> at line number 19
2020-05-10 21:14:50.220 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py': TypeError: 'tuple' object is not callable in <script> at line number 29
2020-05-10 21:14:50.252 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py': TypeError: 'tuple' object is not callable in <script> at line number 18
2020-05-10 21:14:50.277 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py': TypeError: 'tuple' object is not callable in <script> at line number 10
2020-05-10 21:14:50.306 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py': TypeError: 'tuple' object is not callable in <script> at line number 17
2020-05-10 21:14:50.336 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py': TypeError: 'tuple' object is not callable in <script> at line number 17
2020-05-10 21:14:50.362 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/core/components/200_JythonTransform.py': TypeError: 'tuple' object is not callable in <script> at line number 19
2020-05-10 21:14:50.771 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/aaa_keypad-scenes.py': TypeError: 'tuple' object is not callable in <script> at line number 14
2020-05-10 21:14:50.802 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/av-activity.py': TypeError: 'tuple' object is not callable in <script> at line number 4
2020-05-10 21:14:50.819 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/coat-closet-lights-handler.py': TypeError: 'tuple' object is not callable in <script> at line number 5
2020-05-10 21:14:50.837 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/doorbell.py': TypeError: 'tuple' object is not callable in <script> at line number 6
2020-05-10 21:14:50.859 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/fans-delayed-off.py': TypeError: 'tuple' object is not callable in <script> at line number 7
2020-05-10 21:14:50.878 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/hot-water-recirc-pump.py': TypeError: 'tuple' object is not callable in <script> at line number 7
2020-05-10 21:14:50.901 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/kitchen-pendant-handler.py': TypeError: 'tuple' object is not callable in <script> at line number 1
2020-05-10 21:14:50.921 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/scheduled-lights.py': TypeError: 'tuple' object is not callable in <script> at line number 6
2020-05-10 21:14:50.948 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/community/update_mode/update_mode.py': TypeError: 'tuple' object is not callable in <script> at line number 25
2020-05-10 21:14:50.972 [ERROR][ool-20-thread-1][ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/jsr223/python/personal/zzz_motion-lights.py': TypeError: 'tuple' object is not callable in <script> at line number 7

Anyone have any ideas how to get to the bottom of this?

scottk · May 11, 2020, 4:47pm

I puzzled over this, only looking at the various core modules. I finally dug deeper and found the common factor: the modules that failed to load all imported configuration.py. I had introduced a subtle bug/typo when I added one of my new items to an OrderedDict object in configuration.py. I missed adding a comma after that new entry in the OrderedDict, so it was parsed as an attempt to call a tuple on a tuple, which is obviously an error.

For clarity and understanding, excerpt of configuration.py before I added the new entry:

        'loads'                : OrderedDict([
            ('EE_Portal_Lts'       , 'ON'),
            ('EE_Sconces'          , 'ON'),
            ('DW_Lights'           , 'ON'),
            ('EF_RecessedLights'   , 'ON'),
            ('EF_Art_S_Lts'        , 'ON'),
            ('EF_Art_W_Lts'        , 'ON'),
            ('EF_Nichos'           , 'ON'),
            ('EF_Skylt_N'          , 'ON'),
            ('EF_Skylt_Ctr'        , 'ON'),
            ('EF_Skylt_S'          , 'ON'),
            ('EE_Fountain'         , 'ON')
        ])

… after adding the new entry (with bug):

        'loads'                : OrderedDict([
            ('EE_Portal_Lts'       , 'ON'),
            ('EE_Sconces'          , 'ON'),
            ('DW_Lights'           , 'ON'),
            ('DW_HouseNumberLights', 'ON')
            ('EF_RecessedLights'   , 'ON'),
            ('EF_Art_S_Lts'        , 'ON'),
            ('EF_Art_W_Lts'        , 'ON'),
            ('EF_Nichos'           , 'ON'),
            ('EF_Skylt_N'          , 'ON'),
            ('EF_Skylt_Ctr'        , 'ON'),
            ('EF_Skylt_S'          , 'ON'),
            ('EE_Fountain'         , 'ON')
        ])

5iver · May 11, 2020, 5:18pm

Rats… I have some modifications to core.log that would have helped with this. There will be a log entry if configuration.py does not exist or does not contain LOG_PREFIX. I’m trying to focus on some pushes to the libraries today.

scottk · May 11, 2020, 5:48pm

No problem, I learned something through the pain. Looking forward to upcoming scripting and jython updates.

BTW, I tried out the recently released version of jython-standalone-2.7.2, but reverted to 2.7.0 when it had some issues with, coincidentally, OrderedDict objects.

5iver · May 11, 2020, 6:03pm

Interesting… I have been using it without issues. It’s been so stable that I have used it in the Jython addon and was have modified the docs to use it for manual installs. I haven’t noticed any issues with OrderedDicts. What were you seeing?

scottk · May 11, 2020, 6:26pm

I have an extensive keypad scene script and set of related classes. Since I use Lutron RadioRA 2 keypads all over the house to control my lighting (combination of Lutron and ZWave dimmers/relays), I keep the keypad/scene information in my configuration.py. The script creates the necessary groups and linkages between keypad keys and individual scenes, but it also vets all aspects of each scene in configuration.py. One of the checks is that it verifies that the dictionary value associated with the key ‘loads’ from every scene is an OrderedDict object, if not, it logs an error, and after all vetting is complete it throws an exception if anything failed to vet.

Example keypad definition from configuration.py:

    ####################################################################
    #
    # Pantry Keypad
    #
    'Pantry_Lts'       : {
        'mode'         : TOGGLE_MONITOR,
        'group'        : {
            'name'     : 'gPantryLightsScene',
            'label'    : 'Pantry Lights [%s]'
        },
        'keypad_buttons': {
            'KT_Pantry' : 1
        },
        'loads'        : OrderedDict([
            ('KT_Pantry_SW_Uppers' ,  '30'),
            ('KT_Pantry_NE_Uppers' ,  '30'),
            ('KT_Pantry_N_Lowers'  ,  '67'),
            ('KT_Pantry_E_Lowers'  ,  '67'),
            ('KT_Pantry_Lts'       ,  '75')
        ])
    },
    'Pantry_Recessed_Lts': {
        'mode'         : TOGGLE_MONITOR,
        'group'        : {
            'name'     : 'gPantryRecessedLts',
            'label'    : 'Pantry Recessed Lights [%s]'
        },
        'keypad_buttons': {
            'KT_Pantry' : 2
        },
        'loads'        : OrderedDict([
            ('KT_Pantry_Lts'      , '100')
        ])
    },
    'Pantry_Cabinet_Top_Lts': {
        'mode'         : TOGGLE_MONITOR,
        'group'        : {
            'name'     : 'gPantryCabinetTopLts',
            'label'    : 'Pantry Cabinet Tops [%s]'
        },
        'keypad_buttons': {
            'KT_Pantry' : 3
        },
        'loads'        : OrderedDict([
            ('KT_Pantry_SW_Uppers', '35'),
            ('KT_Pantry_NE_Uppers', '35')
        ])
    },
    'Pantry_Cabinet_Btm_Lts': {
        'mode'         : TOGGLE_MONITOR,
        'group'        : {
            'name'     : 'gPantryCabinetBtmLts',
            'label'    : 'Pantry Cabinet Bottoms [%s]'
        },
        'keypad_buttons': {
            'KT_Pantry' : 4
        },
        'loads'        : OrderedDict([
            ('KT_Pantry_N_Lowers' , '67'),
            ('KT_Pantry_E_Lowers' , '67')
        ])
    },
    'Pantry_All_Off': {
        'mode'         : ALL_OFF,
        'group'        : {
            'name'     : 'gPantryAllOffLts',
            'label'    : 'Pantry All Off'
        },
        'keypad_buttons': {
            'KT_Pantry' : 6
        },
        'loads'        : OrderedDict([
            ('KT_Pantry_Lts'      , 'ON'),
            ('KT_Pantry_N_Lowers' , 'ON'),
            ('KT_Pantry_E_Lowers' , 'ON'),
            ('KT_Pantry_SW_Uppers', 'ON'),
            ('KT_Pantry_NE_Uppers', 'ON')
        ])
    },

Method that vets ‘loads’ values:

        def vet_loads():
            if not isinstance(setting, OrderedDict):
                logger.error("'{}': '{}' value is not an OrderedDict instance [{}]."
                             .format(scene_name, LOADS_KEY, type(setting)))
                self.vetted = False

            for load_item, load_level in setting.items():
                item = vet_switch_item(load_item, 'load')
                if item is not None                                                 \
                   and load_level is not None                                       \
                   and not TypeParser.parseState(item.acceptedDataTypes, load_level):
                    logger.error("'{}': '{}' is not a valid load level."
                                 .format(scene_name, load_level))
                    self.vetted = False

Excerpt from the vetting loop:

        # vet all required scene settings
        for scene_name, scene_settings in self.scenes.items():
            for required_setting, vet_setting in {MODE_KEY          : vet_mode,
                                                  KEYPAD_BUTTONS_KEY: vet_keypad_buttons,
                                                  LOADS_KEY         : vet_loads
                                                 }.items():
                setting = scene_settings[required_setting]
                if setting is not None:
                    vet_setting()
                else:
                    logger.error("Scene '{}' has no '{}' setting"
                                 .format(scene_name, required_setting))
                    self.vetted = False

Definitions of string constants used:

BUTTONS_KEY        = 'buttons'
KEYPAD_BUTTONS_KEY = 'keypad_buttons'
LED_GROUP_KEY      = 'led_group'
LOADS_KEY          = 'loads'
MODE_KEY           = 'mode'
MONITOR_GROUP_KEY  = 'monitor_group'
SCENE_KEY          = 'scene'
UNUSED_BUTTONS_KEY = 'unused_buttons'

Log from startup with jython-standalone-2.7.2:

2020-05-11 10:33:19.509 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'GBR2_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.519 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Vestibule_Art_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.527 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Bath2_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.528 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'EF_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.530 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Powder_Room_Mirror_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.530 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Bath2_Vanity_Lt': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.531 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Exterior_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.533 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Entry_Foyer_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.534 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'MBA_Passage_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.538 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Nicho_Lt': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.538 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'GV_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.539 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Entry_Nicho_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.540 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'MR_Ctr_Lt': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.544 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Laundry_Cabinet_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.544 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Pantry_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.545 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'GBA1_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.546 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Vestibule_Ceiling_Lt': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.547 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'PR_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.547 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'MBA_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.548 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Garage_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.549 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Vestibule_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.549 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Closet_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.550 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'GBA2_Night_Light': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.550 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Powder_Room_Ceiling_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.551 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Headboard_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.551 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Bath2_Fan': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.552 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'GBA1_Night_Light': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.552 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Powder_Room_Fan': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.553 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Entry_Fountain': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.553 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Driveway_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.554 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Pantry_Cabinet_Btm_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.555 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Laundry_Fan': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.555 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'MBR_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.556 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Tub_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.556 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'GBR1_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.557 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Desk_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.557 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Entry_Exterior_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.558 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Powder_Room_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.559 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Nicho_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.559 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'GBA2_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.560 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Bath1_Fan': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.561 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Office_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.561 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'MR_Lights': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.562 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Laundry_Rail_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.562 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Shower_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.562 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Bedroom_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.563 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Office_Lights': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.563 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Bath_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.564 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Pantry_Recessed_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.564 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'OF_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.565 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Pantry_Cabinet_Top_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.565 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_WC_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.566 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Master_Bath_Recessed_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.567 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Pantry_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.567 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Laundry_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.568 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Bath1_Vanity_Lt': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.568 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Guest_Bath1_Lts': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.569 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'Garage_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.569 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - 'MR_OF_All_Off': 'loads' value is not an OrderedDict instance.
2020-05-11 10:33:19.571 [ERROR][ool-28-thread-1][jsr223.jython.script.keypad_scenes  ] - Exception Provided scenes have one or more errors.: Traceback (most recent call last):
  File "<script>", line 829, in <module>
  File "<script>", line 469, in __init__
  File "<script>", line 555, in vet_scenes
ValueError: Provided scenes have one or more errors.

Needless to say, there are no errors when using jython-standalone-2.7.0.

When I get a chance, I will try again with the little bit of extra logging output you see in vet_loads() above, i.e., output the type of the object if it is not an OrderedDict.

Cheers!

5iver · May 11, 2020, 9:25pm

Wow… that’s a lot of detail but still isn’t enough to reproduce. I didn’t run into issues with simple tests that I did with 2.7.2 and OrderedDicts. If you want to send me everything, I’ll take a look, but I have no doubt that you are capable of distilling this down to troubleshoot the issue .