OH3.2 strange problems after Java?-Upgrade

Setup, Configuration and Use Runtime
1

My Openhab 3.2 is on a Debian Bullseye machine.

Last week i installed the following system updates:
bsdextrautils 2.36.1-8+deb11u1
bsdutils 1:2.36.1-8+deb11u1
eject 2.36.1-8+deb11u1
fdisk 2.36.1-8+deb11u1
libblkid1 2.36.1-8+deb11u1
libfdisk1 2.36.1-8+deb11u1
libmount1 2.36.1-8+deb11u1
libpolkit-agent-1-0 0.105-31+deb11u1
libpolkit-gobject-1-0 0.105-31+deb11u1
libsmartcols1 2.36.1-8+deb11u1
libuuid1 2.36.1-8+deb11u1
mount 2.36.1-8+deb11u1
openjdk-11-jre 11.0.14+9-1~deb11u1
openjdk-11-jre-headless 11.0.14+9-1~deb11u1
policykit-1 0.105-31+deb11u1
util-linux 2.36.1-8+deb11u1

Before this update everything works fine.
After this update i found the following problems:
I use the Tankerkönig binding to get the prices of 4 stations. For each station and gas type i have rules that listen on item change events. After the update the item change events are only startet for one station and there for all 3 gas types (E10, E5, Diesel).
In the 12 java rules (4 stations x 3 gas types) i have the same program code, only the items are different. In 3 of 12 i get mails from the Mail binding after each change of price.
In the other 9 of 12 i the rules doen’t start. If i start the rules by hand the rules are running fine but the mail binding throws one error:

2022-02-01 19:25:43.200 [WARN ] [ab.binding.mail.internal.SMTPHandler] - Sending the email to the following server failed : smtp.xxx
2022-02-01 19:25:43.200 [WARN ] [ab.binding.mail.internal.SMTPHandler] - javax.mail.MessagingException: IOException while sending message; 
  nested exception is: 
	javax.activation.UnsupportedDataTypeException: text/plain; charset=UTF-8

I found this but i think it is not my problem:

Before the updates (maybe the openjdk-update) everything, every binding and every rule and every sendmail-Actions worked fine. Now only some rules are working fine.

In the events log i find all tankerkönig-items are changed, but only 3 of 12 item change events are working and in 9 of 12 items change rules i can’t send mails, in the other 3 (same code only other items) the mails also working.

Any ideas?

Thank you.

Best regards

Michael

2

If you follow the link to the open issue on that thread you will find that the problem discussed is almost certainly the same as your problem.

3

what is the difference in the content between these two groups ?

4

All 12 items are items changed vom the tankerkönig binding.
4 stations with each 3 gas types = 12 items
1 station with 3 gas type items are working well and 3 stations with 9 items not.
Every of the 12 items has a rule with item change event, 9 are not triggered anymore. If i start the 9 rules manually i got the mail binding error. At the 3 other items everything including mail are working well.
I don’t know the difference.
All 12 items where changed regualry as i see in the event.log. But only 3 items throw the item change event running, the other 9 not.
Before the apt upgrade (updated java) all 12 items and item changed rules were working well.

5

what about differences in content of the mails ?

6

the values of the gas prices and the name of the stations

One of the 9 not functional items with the mail content in the log (DBG-rows):

2022-02-02 15:13:42.100 [INFO ] [telleOilHamburgLangenhorn_E5_Changed] - BEG: 2022-02-02T15:13:42.100541 
2022-02-02 15:13:43.163 [INFO ] [telleOilHamburgLangenhorn_E5_Changed] - DBG: Oil Hamburg E5 von 1,789€ auf 1,789€ gesenkt.  * --- 1,789 - 29.01 09:43 Hamburg 
1,759 - 02.02 15:13 Kummerfeld 
1,779 - 01.02 19:25 Westerhorn 
1,779 - 29.01 09:43 Horst 
1,749 - 01.02 10:09 Gelsenkirchen-Buer 

1,739 - 29.01 09:13 ++++ 
1,769 - 29.01 09:03 -- 
1,779 - 29.01 08:03 - 
1,669 - 28.01 20:43 ++++++++++ 
1,679 - 28.01 20:13 - 
1,689 - 28.01 19:33 - 
1,659 - 28.01 18:33 +++ 
1,669 - 28.01 18:13 - 
1,689 - 28.01 17:33 -- 
1,669 - 28.01 16:33 ++ 
1,679 - 28.01 16:13 - 
1,719 - 28.01 15:33 ---- 
1,679 - 28.01 14:43 ++++ 
1,689 - 28.01 14:23 - 
1,709 - 28.01 13:43 -- 
1,719 - 28.01 13:13 - 
1,729 - 28.01 12:43 - 
1,689 - 28.01 12:13 ++++ 
1,699 - 28.01 12:03 - 

Bisherige günstigste Preise der letzten 7 Tage: 
9,999 - 02.02 00:00 am Mittwoch 
9,999 - 01.02 00:00 am Dienstag 
9,999 - 31.01 00:00 am Montag 
9,999 - 30.01 00:00 am Sonntag 
1,739 - 29.01 09:13 am Samstag 
1,659 - 28.01 05:03 am Freitag 
1,569 - 27.01 17:13 am Donnerstag 

2022-02-02 15:13:44.212 [WARN ] [ab.binding.mail.internal.SMTPHandler] - Sending the email to the following server failed : smtp.fastmail.com:465 
2022-02-02 15:13:44.212 [WARN ] [ab.binding.mail.internal.SMTPHandler] - javax.mail.MessagingException: IOException while sending message; 
  nested exception is: 
        javax.activation.UnsupportedDataTypeException: text/plain; charset=UTF-8 
2022-02-02 15:13:44.863 [INFO ] [telleOilHamburgLangenhorn_E5_Changed] - END: 2022-02-02T15:13:44.863690

This is one mail of the one of the functional 3 ones:

Betreff: HEM Kummerfeld E10 von 1,709€ auf 1,699€ gesenkt. -
Datum: Mittwoch, 02. Februar 2022 15:13

1,709 - 02.02 14:58 Kummerfeld
1,719 - 01.02 09:07 Horst
1,719 - 01.02 19:00 Westerhorn
1,729 - 01.02 10:38 Hamburg
1,689 - 01.02 10:08 Gelsenkirchen-Buer

1,719 - 02.02 14:13 -
1,729 - 02.02 12:58 -
1,769 - 02.02 12:43 ---
1,729 - 02.02 11:43 +++
1,739 - 02.02 09:58 -
1,789 - 02.02 09:43 ----
1,739 - 02.02 08:58 ++++
1,749 - 02.02 08:13 -
1,789 - 02.02 06:58 ---
1,689 - 02.02 06:13 +++++++++
1,629 - 01.02 20:13 ++++++
1,659 - 01.02 19:43 ---
1,629 - 01.02 17:58 +++
1,649 - 01.02 17:43 --
1,629 - 01.02 15:58 ++
1,669 - 01.02 15:43 ----
1,629 - 01.02 14:13 ++++
1,639 - 01.02 13:43 -
1,649 - 01.02 12:58 -

Bisherige günstigste Preise der letzten 7 Tage:
1,689 - 02.02 06:13 am Mittwoch
1,629 - 01.02 14:13 am Dienstag
1,609 - 31.01 21:27 am Montag
1,609 - 30.01 10:43 am Sonntag
1,629 - 29.01 20:34 am Samstag
1,589 - 28.01 06:03 am Freitag
1,519 - 27.01 18:33 am Donnerstag
7

Does that go in the mail title, any accented characters?

8

Crazy: I didn’t changed anything except some additional logging in some rules - and now this:
All tankerkönig-items-changed-rules ran (even the ones i didn’t change at all) and mailed me the action gas prices … the first time after my apt upgrade last saturday.

2022-02-02 16:58:15.612 [INFO ] [TKTankstelleOilWesterhorn_E5_Changed] - BEG: 2022-02-02T16:58:15.612690 
2022-02-02 16:58:16.380 [INFO ] [KTankstelleOilWesterhorn_E10_Changed] - BEG: 2022-02-02T16:58:16.380010 
2022-02-02 16:58:16.397 [INFO ] [telleOilGelsenkirchenBuer_E5_Changed] - BEG: 2022-02-02T16:58:16.397703 
2022-02-02 16:58:16.428 [INFO ] [eOilGelsenkirchenBuer_Diesel_Changed] - BEG: 2022-02-02T16:58:16.427994 
2022-02-02 16:58:16.449 [INFO ] [elleOilHamburgLangenhorn_E10_Changed] - BEG: 2022-02-02T16:58:16.449261 
2022-02-02 16:58:16.454 [INFO ] [elleOilGelsenkirchenBuer_E10_Changed] - BEG: 2022-02-02T16:58:16.454550 
2022-02-02 16:58:16.502 [INFO ] [eOilHamburgLangenhorn_Diesel_Changed] - BEG: 2022-02-02T16:58:16.502028 
2022-02-02 16:58:16.518 [INFO ] [telleOilHamburgLangenhorn_E5_Changed] - BEG: 2022-02-02T16:58:16.518555 
2022-02-02 16:58:16.539 [INFO ] [nkstelleOilWesterhorn_Diesel_Changed] - BEG: 2022-02-02T16:58:16.539695 
2022-02-02 16:58:16.571 [INFO ] [.TKTankstelleOilHorst_Diesel_Changed] - BEG: 2022-02-02T16:58:16.570778 
2022-02-02 16:58:16.603 [INFO ] [ule.TKTankstelleOilHorst_E10_Changed] - BEG: 2022-02-02T16:58:16.603411 
2022-02-02 16:58:16.639 [INFO ] [rule.TKTankstelleOilHorst_E5_Changed] - BEG: 2022-02-02T16:58:16.635171 
2022-02-02 16:58:18.101 [INFO ] [TKTankstelleOilWesterhorn_E5_Changed] - END: 2022-02-02T16:58:18.101073 
2022-02-02 16:58:20.971 [INFO ] [eOilGelsenkirchenBuer_Diesel_Changed] - END: 2022-02-02T16:58:20.970924 
2022-02-02 16:58:21.000 [INFO ] [eOilHamburgLangenhorn_Diesel_Changed] - END: 2022-02-02T16:58:21.000334 
2022-02-02 16:58:21.033 [INFO ] [telleOilGelsenkirchenBuer_E5_Changed] - END: 2022-02-02T16:58:21.033128 
2022-02-02 16:58:21.054 [INFO ] [telleOilHamburgLangenhorn_E5_Changed] - END: 2022-02-02T16:58:21.054184 
2022-02-02 16:58:22.521 [INFO ] [.TKTankstelleOilHorst_Diesel_Changed] - END: 2022-02-02T16:58:22.521052 
2022-02-02 16:58:23.617 [INFO ] [elleOilGelsenkirchenBuer_E10_Changed] - END: 2022-02-02T16:58:23.617455 
2022-02-02 16:58:23.780 [INFO ] [rule.TKTankstelleOilHorst_E5_Changed] - END: 2022-02-02T16:58:23.780232 
2022-02-02 16:58:23.799 [INFO ] [ule.TKTankstelleOilHorst_E10_Changed] - END: 2022-02-02T16:58:23.799510 
2022-02-02 16:58:23.913 [INFO ] [nkstelleOilWesterhorn_Diesel_Changed] - END: 2022-02-02T16:58:23.913872 
2022-02-02 16:58:23.929 [INFO ] [elleOilHamburgLangenhorn_E10_Changed] - END: 2022-02-02T16:58:23.928996 
2022-02-02 16:58:23.932 [INFO ] [KTankstelleOilWesterhorn_E10_Changed] - END: 2022-02-02T16:58:23.932387
9

I think there are two problems:

  1. not every item-changed-event is triggered and
  2. some special problem that causes the send mail action problem.

For now i have changed my item-changed-event-rules with one more trigger: i call them every 10 minutes and check if there was a change. Because the items where changed but the item changed event is not every time triggered i get my statistics in the one or other way, but if the rule is running because of the time trigger i get the send mail error.

Now i have to check all other item-changed-rules if there where the same problems …

10

That’s really unlikely.
Can’t comment on your rules, can’t see them.
I expect they’re big and complicated - don’t forget you can create a little test rule that also triggers on the same event(s) and just makes a little log or similar.

11

my gas rules have 360 rows with several changes of about 40 items with event.postUpdates …
Maybe it is a queue problem when 12 “big” rules want to run at the same time and i have only 4 cpus?
But it looks like alls rules are running parallel: 12 starte (BEG) and 12 stops (END) in the log with about 7 seconds runtime each.