Exec thing stops actualizing according interval

usambara · September 7, 2021, 6:56pm

One of my exec things has a strange behavior. After a certain time (usually several days, sometimes weeks) it isn’t updated automatically as usually. But I can trigger it manually. Also running the command from the console is working without problems.

In the logs below you can see that the last run according to the interval was at 05:23:10 and it received no output.
After this point the command is only executed when the channel ‘run’ is set to ON (in my program every 6 minutes). That’s a workaround to get the data even when the misbehavior occurs.

The wanted behavior can be restored by reloading of the thing file.

I had this behavior since a very long time (with OH 2.x on older Pi and also now with 3.2.0.M1 on Pi 4). But now I’m looking for a solution to get rid of it.

Thing	exec:command:execBLNetQuery		"execBLNetAbfrage" @ "logical"
[
	command="/usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null",
	interval=30, 
	timeout=15,
	autorun=false
]

2021-09-07 05:20:08.934 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:20:08.935 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:20:08.935 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:20:08.973 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:20:08;  89.3;  47.9;  47.8;  88.4;  27.1;  27.2;  45.9;   4.9;  86.3;   9.8;  24.9;  26.0; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:20:08.974 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.3:47.9:47.8:88.4:27.1:27.2:45.9:4.9:86.3:9.8:24.9:26.0:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:20:08.979 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:20:08;  89.3;  47.9;  47.8;  88.4;  27.1;  27.2;  45.9;   4.9;  86.3;   9.8;  24.9;  26.0; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.3:47.9:47.8:88.4:27.1:27.2:45.9:4.9:86.3:9.8:24.9:26.0:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:20:38.981 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:20:38.981 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:20:38.981 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:20:39.019 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:20:39;  89.4;  47.9;  47.8;  88.3;  27.2;  27.2;  45.9;   4.8;  86.3;   9.7;  24.8;  26.0; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:20:39.019 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.4:47.9:47.8:88.3:27.2:27.2:45.9:4.8:86.3:9.7:24.8:26.0:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:20:39.023 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:20:39;  89.4;  47.9;  47.8;  88.3;  27.2;  27.2;  45.9;   4.8;  86.3;   9.7;  24.8;  26.0; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.4:47.9:47.8:88.3:27.2:27.2:45.9:4.8:86.3:9.7:24.8:26.0:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:21:09.972 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:21:09.973 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:21:09.973 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:21:10.011 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:21:10;  89.4;  47.9;  47.8;  88.3;  27.3;  27.2;  45.9;   4.8;  86.3;   9.7;  24.9;  25.9; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:21:10.011 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.4:47.9:47.8:88.3:27.3:27.2:45.9:4.8:86.3:9.7:24.9:25.9:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:21:10.016 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:21:10;  89.4;  47.9;  47.8;  88.3;  27.3;  27.2;  45.9;   4.8;  86.3;   9.7;  24.9;  25.9; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.4:47.9:47.8:88.3:27.3:27.2:45.9:4.8:86.3:9.7:24.9:25.9:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:21:40.017 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:21:40.017 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:21:40.017 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:21:40.055 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:21:40;  89.3;  47.9;  47.8;  88.3;  27.1;  27.3;  46.0;   4.8;  86.3;   9.7;  24.9;  25.9; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:21:40.055 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.3:47.9:47.8:88.3:27.1:27.3:46.0:4.8:86.3:9.7:24.9:25.9:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:21:40.058 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:21:40;  89.3;  47.9;  47.8;  88.3;  27.1;  27.3;  46.0;   4.8;  86.3;   9.7;  24.9;  25.9; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.3:47.9:47.8:88.3:27.1:27.3:46.0:4.8:86.3:9.7:24.9:25.9:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:22:10.297 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:22:10.297 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:22:10.297 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:22:10.333 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:22:10;  89.3;  47.9;  47.8;  88.4;  27.1;  27.2;  46.4;   4.9;  86.3;   9.8;  25.0;  25.7; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:22:10.334 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.3:47.9:47.8:88.4:27.1:27.2:46.4:4.9:86.3:9.8:25.0:25.7:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:22:10.341 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:22:10;  89.3;  47.9;  47.8;  88.4;  27.1;  27.2;  46.4;   4.9;  86.3;   9.8;  25.0;  25.7; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.3:47.9:47.8:88.4:27.1:27.2:46.4:4.9:86.3:9.8:25.0:25.7:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:22:40.342 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:22:40.343 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:22:40.343 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:22:40.383 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:22:40;  89.4;  47.9;  47.9;  88.3;  27.1;  27.2;  46.8;   4.9;  86.2;   9.7;  24.9;  25.7; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:22:40.384 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.4:47.9:47.9:88.3:27.1:27.2:46.8:4.9:86.2:9.7:24.9:25.7:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:22:40.390 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:22:40;  89.4;  47.9;  47.9;  88.3;  27.1;  27.2;  46.8;   4.9;  86.2;   9.7;  24.9;  25.7; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.4:47.9:47.9:88.3:27.1:27.2:46.8:4.9:86.2:9.7:24.9:25.7:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:23:10.937 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:23:10.937 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:23:10.937 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:28:01.488 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:28:01.488 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:28:01.488 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:28:01.532 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:28:01;  89.4;  50.7;  48.1;  88.3;  27.3;  27.3;  48.5;   4.8;  86.3;   9.6;  24.8;  25.2; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:28:01.532 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.4:50.7:48.1:88.3:27.3:27.3:48.5:4.8:86.3:9.6:24.8:25.2:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:1:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:28:01.537 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:28:01;  89.4;  50.7;  48.1;  88.3;  27.3;  27.3;  48.5;   4.8;  86.3;   9.6;  24.8;  25.2; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.4:50.7:48.1:88.3:27.3:27.3:48.5:4.8:86.3:9.6:24.8:25.2:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:1:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:34:02.021 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:34:02.022 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:34:02.022 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:34:02.057 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:34:02;  89.3;  51.6;  48.0;  88.3;  27.2;  27.3;  48.2;   4.7;  86.3;   9.6;  25.6;  25.0; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:34:02.058 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.3:51.6:48.0:88.3:27.2:27.3:48.2:4.7:86.3:9.6:25.6:25.0:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:1:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:34:02.065 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:34:02;  89.3;  51.6;  48.0;  88.3;  27.2;  27.3;  48.2;   4.7;  86.3;   9.6;  25.6;  25.0; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.3:51.6:48.0:88.3:27.2:27.3:48.2:4.7:86.3:9.6:25.6:25.0:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:1:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:40:02.189 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-07 05:40:02.189 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-07 05:40:02.189 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd 2> /dev/null]'
2021-09-07 05:40:02.225 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '07.09.21;05:40:02;  89.3;  51.9;  48.0;  88.3;  27.2;  27.3;  48.2;   4.6;  86.2;   9.6;  27.7;  30.6; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-07 05:40:02.226 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '89.3:51.9:48.0:88.3:27.2:27.3:48.2:4.6:86.2:9.6:27.7:30.6:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:1:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-07 05:40:02.231 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '07.09.21;05:40:02;  89.3;  51.9;  48.0;  88.3;  27.2;  27.3;  48.2;   4.6;  86.2;   9.6;  27.7;  30.6; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 1; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
89.3:51.9:48.0:88.3:27.2:27.3:48.2:4.6:86.2:9.6:27.7:30.6:409.5:-409.6:0.0:51.1:0:0:0:0:1:0:1:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'


runtimeInfo:
  version: 3.2.0.M1
  buildString: Milestone Build
locale: de-DE
systemInfo:
  configFolder: /etc/openhab
  userdataFolder: /var/lib/openhab
  logFolder: /var/log/openhab
  javaVersion: 11.0.11
  javaVendor: Azul Systems, Inc.
  javaVendorVersion: Zulu11.48+21-CA
  osName: Linux
  osVersion: 5.10.60-v8+
  osArchitecture: aarch64
  availableProcessors: 4
  freeMemory: 39994808
  totalMemory: 283115520

Wolfgang_S · September 9, 2021, 3:19pm

Does it make sense to record the output of STDERR and instead of throwing it away to collect it for some time ? Redirect it to a file e.g. 2>> /tmp/error. May be for some reason an error happens once and the Exec binding struggles somehow.
Chance might be low that this is the case but checking the output of STDERR should give a clue.

rossko57 · September 9, 2021, 3:43pm

It is disappointing that DEBUG doesn’t mention scheduling action.

That double OUTPUT is bit curious too, although it seems to mash it into one for the transform step. Maybe that’s just how it logs long strings.

It’s not clear if your six minute run trigger rule is active alongside the auto-interval. Maybe it doesn’t play nice if they clash.

usambara · September 9, 2021, 5:53pm

Thanks for your ideas.

The run after 6 minutes is only triggered if there was no update for 5 minutes, so the don’t run in parallel.

The multiline output is as expected, just the error channel is twice. When I run the command at the console I get that answer:


 Adresse:port gesetzt: 192.168.44.11:40000
 CAN-Logging: uvr_modus -> A8 
09.09.21;19:48:44;  84.8;  47.9;  50.9;  83.9;  30.6;  32.1;  25.5;  23.5;  82.3;  18.9;  24.5;  25.4; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
84.8:47.9:50.9:83.9:30.6:32.1:25.5:23.5:82.3:18.9:24.5:25.4:409.5:-409.6:0.0:51.1:0:0:0:0:0:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0

This gets transformed into:

01.09.21;23:59:52;  68.7;  58.5;  37.4;  67.6;  26.0;  26.0;  39.1;   6.5;  65.4;  11.5;  22.6;  27.0; 409.5; -409.6;   0.0;  51.1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
68.7:58.5:37.4:67.6:26.0:26.0:39.1:6.5:65.4:11.5:22.6:27.0:409.5:-409.6:0.0:51.1:0:0:0:0:0:0:0:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0

 Adresse:port gesetzt: 192.168.44.11:40000
 CAN-Logging: uvr_modus -> A8 

 Adresse:port gesetzt: 192.168.44.11:40000
 CAN-Logging: uvr_modus -> A8

The error channel is filtered out as that program uses this for some additional information, which isn’t needed for my purpose. Here an example with the ERROR output. With the second run (11:23:35) it’s stuck again. There is no additional information. But I’ll give it a trial and check it when it will get stuck the next time.

2021-09-02 11:23:05.553 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-02 11:23:05.554 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-02 11:23:05.554 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd]'
2021-09-02 11:23:05.595 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '02.09.21;11:23:05;  64.6;  55.1;  34.5;  62.9;  80.1;  43.6;  37.2;  94.1;  59.9;  15.5;  20.1;  26.5; 409.5; -409.6;   0.0;  51.1; 1;30; 0; 0; 1; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;'
2021-09-02 11:23:05.596 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [OUTPUT]: '64.6:55.1:34.5:62.9:80.1:43.6:37.2:94.1:59.9:15.5:20.1:26.5:409.5:-409.6:0.0:51.1:1:30:0:0:1:0:1:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0'
2021-09-02 11:23:05.596 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [ERROR]: ''
2021-09-02 11:23:05.597 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [ERROR]: ' Adresse:port gesetzt: 192.168.44.11:40000'
2021-09-02 11:23:05.597 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Exec [ERROR]: ' CAN-Logging: uvr_modus -> A8 '
2021-09-02 11:23:05.602 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Transformed response is '02.09.21;11:23:05;  64.6;  55.1;  34.5;  62.9;  80.1;  43.6;  37.2;  94.1;  59.9;  15.5;  20.1;  26.5; 409.5; -409.6;   0.0;  51.1; 1;30; 0; 0; 1; 0; 1; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0; 0.0;00.0;  ---;  ---;
64.6:55.1:34.5:62.9:80.1:43.6:37.2:94.1:59.9:15.5:20.1:26.5:409.5:-409.6:0.0:51.1:1:30:0:0:1:0:1:0:0:0:0:0:0:0:0:0:0:0.0:0:0.0:0:0

 Adresse:port gesetzt: 192.168.44.11:40000
 CAN-Logging: uvr_modus -> A8 

 Adresse:port gesetzt: 192.168.44.11:40000
 CAN-Logging: uvr_modus -> A8'
2021-09-02 11:23:35.603 [DEBUG] [ng.exec.internal.handler.ExecHandler] - Passing to shell for parsing command.
2021-09-02 11:23:35.604 [DEBUG] [ng.exec.internal.handler.ExecHandler] - OS: *NIX (Linux)
2021-09-02 11:23:35.604 [TRACE] [ng.exec.internal.handler.ExecHandler] - The command to be executed will be '[sh, -c, /usr/local/bin/dl-aktuelle-datenx -i 192.168.44.11 -t 0 --rrd]'

I wrote in my last email, it works again after the reloading of the things file. That’s correct, but just a ‘touch’ on the file does not help:
2021-09-09 18:37:36.509 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'exec_heating.things'
An overwrite of the file with the identical one, leads to two lines in the log and a running job.

2021-09-09 18:46:43.079 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'exec_heating.things'
2021-09-09 18:46:44.201 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'exec_heating.things'

usambara · September 22, 2021, 7:02pm

Now I got the error again and the logged STDERR showed nothing special.
It shows always the same lines, which are as expected:

 Adresse:port gesetzt: 192.168.44.11:40000
 CAN-Logging: uvr_modus -> A8 

 Adresse:port gesetzt: 192.168.44.11:40000
 CAN-Logging: uvr_modus -> A8