NameError: name 'DateTime' is not defined from every single script file

rubens · December 21, 2021, 9:39pm

Summary:

OpenHAB 2.5 here, the server had been running for months w/o any issue.
In order to add -Dlog4j2.formatMsgNoLookups=true to EXTRA_JAVA_OPTS in /etc/defaults/openhab2 I restarted the service and now every script file fails to load.

Platform information:
- Hardware: CPUArchitecture/RAM/storage
  raspi 3b,
- OS: what OS is used and which version
  openhabian
- Java Runtime Environment: which java platform is used and what version

openjdk version “1.8.0_222”
OpenJDK Runtime Environment (Zulu8.40.0.178-CA-linux_aarch32hf) (build 1.8.0_222-b178)
OpenJDK Client VM (Zulu8.40.0.178-CA-linux_aarch32hf) (build 25.222-b178, mixed mode, Evaluation)

openHAB version:
the final 2.5 version, 2.5.12-1
Issue of the topic: please be detailed explaining your issue
everything was running smoothly when I came around Kai Kreuzer on log4j and decided to fix that.

I edited /etc/default/openhab2 and restarted the service.
Nothing works any more, every script file fails to load.
I reversed my changes to the defaults but it didn’t help.

The failures:

2021-12-21 21:38:50.455 [INFO ] [jsr223.jython.core.startup_delay] - Checking for initialized context
2021-12-21 21:38:50.472 [INFO ] [jsr223.jython.core.startup_delay] - Context initialized... waiting 30s before allowing scripts to load
2021-12-21 21:38:57.294 [DEBUG] [org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl] - Executing startup rule 'triggered by system start start'
2021-12-21 21:39:20.483 [INFO ] [jsr223.jython.core.startup_delay] - Complete
2021-12-21 21:39:22.290 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/100_DirectoryTrigger.py': NameError: name 'DateTime' is not defined in <script> at line number 21
2021-12-21 21:39:23.022 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/100_OsgiEventTrigger.py': NameError: name 'DateTime' is not defined in <script> at line number 17
2021-12-21 21:39:23.087 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/100_StartupTrigger.py': NameError: name 'DateTime' is not defined in <script> at line number 16
2021-12-21 21:39:23.229 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py': NameError: name 'DateTime' is not defined in <script> at line number 19
2021-12-21 21:39:24.486 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonExtensionProvider.py': NameError: name 'DateTime' is not defined in <script> at line number 29
2021-12-21 21:39:24.580 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py': NameError: name 'DateTime' is not defined in <script> at line number 18
2021-12-21 21:39:24.639 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonItemProvider.py': NameError: name 'DateTime' is not defined in <script> at line number 10
2021-12-21 21:39:24.724 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonThingProvider.py': NameError: name 'DateTime' is not defined in <script> at line number 17
2021-12-21 21:39:24.811 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py': NameError: name 'DateTime' is not defined in <script> at line number 17
2021-12-21 21:39:24.863 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonTransform.py': NameError: name 'DateTime' is not defined in <script> at line number 19
2021-12-21 21:39:26.766 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/310_startup.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:26.855 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/320_initItemStates.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:27.553 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/330_r48mq.py': NameError: name 'DateTime' is not defined in <script> at line number 5
2021-12-21 21:39:27.970 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/350_coloring.py': NameError: name 'DateTime' is not defined in <script> at line number 41
2021-12-21 21:39:28.187 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/355_connect.py': NameError: name 'DateTime' is not defined in <script> at line number 6
2021-12-21 21:39:28.336 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/360_phasen.py': NameError: name 'DateTime' is not defined in <script> at line number 8
2021-12-21 21:39:28.449 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/370_stateBtn.py': NameError: name 'DateTime' is not defined in <script> at line number 4
2021-12-21 21:39:28.609 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/410_panel.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:28.688 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/420_ullu.py': NameError: name 'DateTime' is not defined in <script> at line number 6
2021-12-21 21:39:28.757 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/430_z2m_netmap.py': NameError: name 'DateTime' is not defined in <script> at line number 4
2021-12-21 21:39:29.088 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/601_flur.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:29.540 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/602_bad.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:29.717 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/603_kueche.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:29.884 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/604_balkon.py': NameError: name 'DateTime' is not defined in <script> at line number 4
2021-12-21 21:39:30.222 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/605_SK.py': NameError: name 'DateTime' is not defined in <script> at line number 4
2021-12-21 21:39:30.367 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/606_clara.py': NameError: name 'DateTime' is not defined in <script> at line number 1
2021-12-21 21:39:30.919 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/607_medi.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:31.098 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/608_office.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:31.166 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/720_sensorCtl.py': NameError: name 'DateTime' is not defined in <script> at line number 2
2021-12-21 21:39:31.242 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/910_telegram.py': NameError: name 'DateTime' is not defined in <script> at line number 4
2021-12-21 21:39:31.352 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/923_vbb.py': NameError: name 'DateTime' is not defined in <script> at line number 1
2021-12-21 21:39:31.600 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/930_presence.py': NameError: name 'DateTime' is not defined in <script> at line number 1
2021-12-21 21:39:31.929 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/940_talk.py': NameError: name 'DateTime' is not defined in <script> at line number 1
2021-12-21 21:39:32.148 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/950_checksAndReminder.py': NameError: name 'DateTime' is not defined in <script> at line number 5
2021-12-21 21:39:32.802 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/960_mqParseSensors.py': NameError: name 'DateTime' is not defined in <script> at line number 1
2021-12-21 21:39:32.884 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/961_mqTasmota.py': NameError: name 'DateTime' is not defined in <script> at line number 4
2021-12-21 21:39:33.000 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/962_mqParseHealth.py': NameError: name 'DateTime' is not defined in <script> at line number 4
2021-12-21 21:39:33.103 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/965_mqParsePresence.py': NameError: name 'DateTime' is not defined in <script> at line number 1
2021-12-21 21:39:33.206 [ERROR] [org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/etc/openhab2/automation/jsr223/python/personal/980_watchdog.py': NameError: name 'DateTime' is not defined in <script> at line number 2

the /etc/default/openhab2:

 
# openHAB 2 service options

#########################
## PORTS
## The ports openHAB will bind its HTTP/HTTPS web server to.

#OPENHAB_HTTP_PORT=8080
#OPENHAB_HTTPS_PORT=8443

#########################
## HTTP(S) LISTEN ADDRESS
##  The listen address used by the HTTP(S) server.
##  0.0.0.0 (default) allows a connection from any location
##  127.0.0.1 only allows the local machine to connect

#OPENHAB_HTTP_ADDRESS=0.0.0.0

#########################
## BACKUP DIRECTORY
## Set the following variable to specify the backup location.
## runtime/bin/backup and runtime/bin/restore will use this path for the zip files.

#OPENHAB_BACKUPS=/var/lib/openhab2/backups

#########################
## JAVA OPTIONS
## Additional options for the JAVA_OPTS environment variable.
## These will be appended to the execution of the openHAB Java runtime in front of all other options.
## 
## A couple of independent examples:
##   EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyAMA0"
##   EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyS0:/dev/ttyS2:/dev/ttyACM0:/dev/ttyAMA0"
##   EXTRA_JAVA_OPTS="-Djna.library.path=/lib/arm-linux-gnueabihf/ -Duser.timezone=Europe/Berlin -Dgnu.io.rxtx.SerialPorts=/dev/ttyS0"
#EXTRA_JAVA_OPTS="-Djetty.keystore.path=/etc/openhab2/keystore"
#EXTRA_JAVA_OPTS="-Xms250m -Xmx350m -Xbootclasspath/a:/etc/openhab2/automation/jython/jython-standalone-2.7.0.jar -Dpython.home=/etc/openhab2/automation/jython -Dpython.path=/etc/openhab2/automation/lib/python"

EXTRA_JAVA_OPTS="-Xms250m -Xmx350m  -Dpython.home=/etc/openhab2/automation/jython -Dpython.path=/etc/openhab2/automation/lib/python -Djetty.keystore.path=/etc/openhab2/keystore"
## bugfix 
#EXTRA_JAVA_OPTS="-Xms250m -Xmx350m  -Dpython.home=/etc/openhab2/automation/jython -Dpython.path=/etc/openhab2/automation/lib/python -Djetty.keystore.path=/etc/openhab2/keystore -Dlog4j2.formatMsgNoLookups=true"



#########################
## OPENHAB DEFAULTS PATHS
## The following settings override the default apt/rpm locations and should be used with caution.
## openHAB will fail to update itself if you're using different paths. 
## Only set these if you are testing and are confident in debugging.
 
#OPENHAB_HOME=/usr/share/openhab2
#OPENHAB_CONF=/etc/openhab2
#OPENHAB_RUNTIME=/usr/share/openhab2/runtime
#OPENHAB_USERDATA=/var/lib/openhab2
#OPENHAB_LOGDIR=/var/log/openhab2

#########################
## OPENHAB USER AND GROUP
## The user and group that takes ownership of openHAB. Only available for init.d systems.
## To edit user and group for systemd, see the service file at /usr/lib/systemd/system/openhab2.service.

#OPENHAB_USER=openhab
#OPENHAB_GROUP=openhab

#########################
## SYSTEMD START MODE
## The Karaf startmode for the openHAB runtime. Only available for systemctl/systemd systems.
## Defaults to daemon when unset here. Multiple options can be used without quotes. 
## debug increases log output. daemon launches the Karaf/openHAB processes. 

#OPENHAB_STARTMODE=debug

and the scripts start like:


from core.rules import rule
from core.triggers import when
from core.log import logging, LOG_PREFIX

from org.joda.time import DateTime
#import org.joda.time.DateTime as DateTime

from core.date import seconds_between, human_readable_seconds 

from core.actions import LogAction
#from core.actions import PersistenceExtensions

logTag="startup"
 
def logg (msg):
    LogAction.logInfo(logTag,u"{}".format(msg))

def logd (msg):
    #logg(msg)
    pass


logg("init {}".format(logTag))


# System started
@rule("systemStarted", description="triggered  by System started or file reload", tags=["system"])
@when("System started")
def systemStarted(event):
    # system up timestamp
    events.postUpdate("systemUpTimeStamp","{}".format(DateTime.now()) )

I tried a different way to import DateTime, no change, but I don’t think the problem is on the script level. They all did fine and all fail now.

What’s happening here and how I can set things right again? I’m completly lost.

rubens · December 21, 2021, 11:29pm

I tried things now, commenting line by line.
Turns out that the line:

from core.rules import rule

already triggers the NameError: name 'DateTime' is not defined

Where should I look to check what creates me such an error?

So I started to look at those lines the error messages complain about. No DateTime there.

/etc/openhab2/automation/jsr223/python/core/components/100_DirectoryTrigger.py line 21:
from core.log import logging, log_traceback, LOG_PREFIX

/etc/openhab2/automation/jsr223/python/core/components/100_OsgiEventTrigger.py line 17:
from core.osgi.events import OsgiEventAdmin, event_dict, osgi_triggers

/etc/openhab2/automation/jsr223/python/core/components/100_StartupTrigger.py line 16:
from core.log import logging, LOG_PREFIX

/etc/openhab2/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py line 19:
from core.log import logging, LOG_PREFIX

/etc/openhab2/automation/jsr223/python/core/components/200_JythonExtensionProvider.py line 29:
from core.log import logging, LOG_PREFIX

How does the error msg’s text fit to those imports?

rubens · December 22, 2021, 12:50am

Checking systemctl status openhab2 I notice this line:


Dec 22 01:14:55 tieke karaf[11504]: org.ops4j.pax.logging.pax-logging-api [log4j2] ERROR : RegexFilter contains an invalid element or attribute "onMismatch" Ignored FQCN: org.apache.logging.log4j.spi.AbstractLogger

so I cd into /var/lib/openhab2 and search for “onMismatch”, I get a hit at
Binary file ./../openhab2/tmp/packages/rt.pkc matches

Another search grep "org.apache.logging.log4j.spi.AbstractLogger" ./* -r finds
``Binary file ./cache/org.eclipse.osgi/6/0/bundleFile matches´´

So I clear the cache/ and tmp/ directories and restart openhab2.
No change, both files have been recreated.

Andrew_Rowe · December 22, 2021, 1:21am

Wow, Daniel, great job so far, this seems as it might be related to the hastily included patch for the recent security vulnerablity