SVG-Plot unterschlägt Daten

Joachim · 09 April 2013, 12:41:40

Moin @ all,
ich bin auf ein nicht nachvollziehbares Problem im SVG-Plot gestossen.

Manchmal werden im Plot Anfangswerte unterschlagen und der Plot ist damit unvollständig.
In diesem Beispiel betrifft es die Abluft.
Bilder sagen mehr als Worte:

(siehe Anhang / see attachement)

Ich habe das Problem auf einem unabhängigem Rechner mit einem frischem FHEM und folgender Konfiguration reproduzieren können.
-fhem.cfg
-WHR960.gplot
WHR960-2013-04.log

als Anhang in SVG.zip

Mit folgenden Änderungen in der 01_FHEMWEB.pm

Code Auswählen


  if($zoom eq "hour") {
    my $t = $now + $off*3600;
    my @l = localtime($t);
    $FW_devs{$d}{from}
        = sprintf("%04d-%02d-%02d_%02d",$l[5]+1900,$l[4]+1,$l[3],$l[2]);
    @l = localtime($t+3600);
    $FW_devs{$d}{to}
        = sprintf("%04d-%02d-%02d_%02d",$l[5]+1900,$l[4]+1,$l[3],$l[2]);
		substr($FW_devs{$d}{to},13,6,":00:01");## >> Auffuellen auf YYYY-MM-DD_HH:MM:SS
		
  } elsif($zoom eq "qday") {
    my $t = $now + $off*21600;
    my @l = localtime($t);
    $l[2] = int($l[2]/6)*6;
    $FW_devs{$d}{from}
        = sprintf("%04d-%02d-%02d_%02d",$l[5]+1900,$l[4]+1,$l[3],$l[2]);
    @l = localtime($t+21600);
    $l[2] = int($l[2]/6)*6;
    $FW_devs{$d}{to}
        = sprintf("%04d-%02d-%02d_%02d",$l[5]+1900,$l[4]+1,$l[3],$l[2]);
		substr($FW_devs{$d}{to},13,6,":00:01");## >> Auffuellen auf YYYY-MM-DD_HH:MM:SS

  } elsif($zoom eq "day") {
    my $t = $now + $off*86400;
    my @l = localtime($t);
    $FW_devs{$d}{from} = sprintf("%04d-%02d-%02d",$l[5]+1900,$l[4]+1,$l[3]);
    @l = localtime($t+86400);
    $FW_devs{$d}{to}   = sprintf("%04d-%02d-%02d",$l[5]+1900,$l[4]+1,$l[3]);
		substr($FW_devs{$d}{to},10,9,"_00:00:01");## >> Auffuellen auf YYYY-MM-DD_HH:MM:SS

  } elsif($zoom eq "week") {
    my @l = localtime($now);
    my $start = (AttrVal($FW_wname, "endPlotToday", undef) ? 6 : $l[6]);
    my $t = $now - ($start*86400) + ($off*86400)*7;
    @l = localtime($t);
    $FW_devs{$d}{from} = sprintf("%04d-%02d-%02d",$l[5]+1900,$l[4]+1,$l[3]);
    @l = localtime($t+7*86400);
    $FW_devs{$d}{to}   = sprintf("%04d-%02d-%02d",$l[5]+1900,$l[4]+1,$l[3]);
		substr($FW_devs{$d}{to},10,9,"_00:00:01");## >> Auffuellen auf YYYY-MM-DD_HH:MM:SS

 } elsif($zoom eq "month") {
    my ($endDay, @l);
    if(AttrVal($FW_wname, "endPlotToday", undef)) {
      @l = localtime($now+86400);
      $endDay = $l[3];
      $off--;
    } else {
      @l = localtime($now);
      $endDay = 1;
    }
    while($off < -12) { # Correct the year
      $off += 12; $l[5]--;
    }
    $l[4] += $off;
    $l[4] += 12, $l[5]-- if($l[4] < 0);
    $FW_devs{$d}{from} = sprintf("%04d-%02d-%02d", $l[5]+1900, $l[4]+1,$endDay);

    $l[4]++;
    $l[4] = 0, $l[5]++ if($l[4] == 12);
    $FW_devs{$d}{to}   = sprintf("%04d-%02d-%02d", $l[5]+1900, $l[4]+1,$endDay);
		substr($FW_devs{$d}{to},10,9,"_00:00:01");## >> Auffuellen auf YYYY-MM-DD_HH:MM:SS
		
  } elsif($zoom eq "year") {
    my @l = localtime($now);
    $l[5] += $off;
    $FW_devs{$d}{from} = sprintf("%04d", $l[5]+1900);
    $FW_devs{$d}{to}   = sprintf("%04d", $l[5]+1901);
		substr($FW_devs{$d}{to},4,15,"-01-01_00:00:01");## >> Auffuellen auf YYYY-MM-DD_HH:MM:SS
	}
}

wird zumindest der hintere Teil vollständig angezeigt.

(siehe Anhang / see attachement)

Gruß Joachim

rudolfkoenig · 09 April 2013, 12:51:15

Wenn ich es richtig verstehe, Du vermisst in dem Plot von gestern, dass der Wert von heute um 00:00:00 nicht beruecksichtigt/angezeigt wird. Ist das richtig?

Joachim · 09 April 2013, 12:57:59

Moin rudolfkoenig,

Nein, es fehlt im Plot vom 8.4 der Anfangswert von 0:00 Uhr, obwohl er im Log vorhanden ist.

2013-04-07_23:56:05 WHR960 ErdWT: 3
2013-04-08_00:00:00 WHR960 Abluft: 17.5 <<<< dieser hier
2013-04-08_00:00:00 WHR960 ErdWT: 3
2013-04-08_00:00:00 WHR960 Fortluft: 6.5
2013-04-08_00:00:00 WHR960 Frischluft: 5
2013-04-08_00:00:00 WHR960 Komf_Temp: 24
2013-04-08_00:00:00 WHR960 Zuluft: 16
2013-04-08_00:01:18 WHR960 ErdWT: 3.5

Im Plot vom 7.4. passiert das gleiche

(siehe Anhang / see attachement)

auch hier ist der Anfangswert vorhanden.

2013-04-06_23:58:30 WHR960 ErdWT: 3
2013-04-07_00:00:00 WHR960 Abluft: 17.5 <<<< dieser hier
2013-04-07_00:00:00 WHR960 ErdWT: 3
2013-04-07_00:00:00 WHR960 Fortluft: 6.5
2013-04-07_00:00:00 WHR960 Frischluft: 5
2013-04-07_00:00:00 WHR960 Komf_Temp: 24
2013-04-07_00:00:00 WHR960 Zuluft: 16
2013-04-07_00:08:35 WHR960 ErdWT: 3

gruß Joachim

Joachim · 09 April 2013, 13:24:03

Neues Beispiel von heute ganz anderer Computer,

(siehe Anhang / see attachement)

Code Auswählen


2013-04-08_23:59:59 MAX_Bad_Fenst battery: ok
2013-04-08_23:59:59 MAX_Bad_Fenst onoff: 0
2013-04-08_23:59:59 MAX_Bad battery: ok
2013-04-08_23:59:59 MAX_Bad desiredTemperature: 18.5
2013-04-08_23:59:59 MAX_Bad valveposition: 0
2013-04-08_23:59:59 MAX_Bad temperature: 21.2
2013-04-08_23:59:59 OWX_Bad T: 19.62 °C
2013-04-09_00:00:00 MAX_Bad_Fenst battery: ok
2013-04-09_00:00:00 MAX_Bad_Fenst onoff: 0
2013-04-09_00:00:00 MAX_Bad battery: ok
2013-04-09_00:00:00 MAX_Bad desiredTemperature: 18.5
2013-04-09_00:00:00 MAX_Bad valveposition: 0
2013-04-09_00:00:00 MAX_Bad temperature: 21.2
2013-04-09_00:00:00 OWX_Bad T: 19.62 °C
2013-04-09_00:06:42 OWX_Bad T: 19.62 °C
2013-04-09_00:11:42 OWX_Bad T: 19.56 °C
2013-04-09_00:12:53 HM_Bad deviceMsg: on (to HMLAN)
2013-04-09_00:12:53 HM_Bad deviceMsg: on (to HMLAN)
2013-04-09_00:12:53 HM_Bad level: 100 %
2013-04-09_00:12:53 HM_Bad deviceMsg: on (to HMLAN)
2013-04-09_00:14:00 HM_Bad level: 0 %
2013-04-09_00:14:00 HM_Bad deviceMsg: off (to HMLAN)
2013-04-09_00:14:01 HM_Bad deviceMsg: off (to HMLAN)
2013-04-09_00:14:01 HM_Bad level: 0 %
2013-04-09_00:14:01 HM_Bad deviceMsg: off (to HMLAN)
2013-04-09_00:16:42 OWX_Bad T: 19.62 °C
2013-04-09_00:20:26 MAX_Bad valveposition: 0
2013-04-09_00:20:26 MAX_Bad temperature: 21.2
2013-04-09_00:21:42 OWX_Bad T: 19.56 °C
2013-04-09_00:25:31 MAX_Bad valveposition: 5
2013-04-09_00:25:31 MAX_Bad temperature: 19.6
2013-04-09_00:26:42 OWX_Bad T: 19.62 °C
2013-04-09_00:31:42 OWX_Bad T: 19.56 °C
2013-04-09_00:36:42 OWX_Bad T: 19.56 °C
2013-04-09_00:41:42 OWX_Bad T: 19.50 °C
2013-04-09_00:45:50 MAX_Bad valveposition: 5
2013-04-09_00:45:50 MAX_Bad temperature: 19.6
2013-04-09_00:50:55 MAX_Bad valveposition: 10
2013-04-09_00:50:55 MAX_Bad temperature: 19.2
2013-04-09_01:11:42 OWX_Bad T: 19.50 °C
2013-04-09_01:16:42 OWX_Bad T: 19.44 °C
2013-04-09_01:26:31 MAX_Bad temperature: 19.2
2013-04-09_01:30:03 MAX_Bad desiredTemperature auto
2013-04-09_01:35:13 MAX_Bad valveposition: 10
2013-04-09_01:40:17 MAX_Bad valveposition: 12
2013-04-09_01:40:17 MAX_Bad temperature: 18.9
2013-04-09_02:30:59 MAX_Bad valveposition: 12
2013-04-09_02:30:59 MAX_Bad temperature: 18.9
2013-04-09_02:36:03 MAX_Bad valveposition: 10
2013-04-09_02:36:03 MAX_Bad temperature: 19.2
2013-04-09_02:46:42 OWX_Bad T: 19.44 °C
2013-04-09_02:51:42 OWX_Bad T: 19.38 °C
2013-04-09_03:11:42 OWX_Bad T: 19.38 °C
2013-04-09_03:16:39 MAX_Bad temperature: 19.2
2013-04-09_03:16:44 OWX_Bad T: 19.31 °C
2013-04-09_03:21:53 OWX_Bad T: 19.38 °C
2013-04-09_03:31:53 MAX_Bad valveposition: 10
2013-04-09_03:31:56 OWX_Bad T: 19.38 °C
2013-04-09_03:36:55 OWX_Bad T: 19.31 °C
2013-04-09_03:36:58 MAX_Bad valveposition: 12
2013-04-09_03:36:58 MAX_Bad temperature: 18.9
2013-04-09_04:27:42 MAX_Bad valveposition: 12
2013-04-09_04:27:42 MAX_Bad temperature: 18.9
2013-04-09_04:32:46 MAX_Bad valveposition: 10
2013-04-09_04:32:46 MAX_Bad temperature: 19.2
2013-04-09_04:46:55 OWX_Bad T: 19.31 °C
2013-04-09_04:51:55 OWX_Bad T: 19.25 °C
2013-04-09_05:21:55 OWX_Bad T: 19.25 °C
2013-04-09_05:23:31 MAX_Bad valveposition: 10
2013-04-09_05:23:31 MAX_Bad temperature: 19.2
2013-04-09_05:26:55 OWX_Bad T: 19.19 °C
2013-04-09_05:28:36 MAX_Bad desiredTemperature: 18.5
2013-04-09_05:28:36 MAX_Bad valveposition: 12
2013-04-09_05:28:36 MAX_Bad temperature: 18.9
2013-04-09_05:31:55 OWX_Bad T: 19.25 °C
2013-04-09_05:33:40 MAX_Bad desiredTemperature: 20.0
2013-04-09_05:33:40 MAX_Bad valveposition: 71
2013-04-09_05:36:55 OWX_Bad T: 19.19 °C
2013-04-09_05:41:55 OWX_Bad T: 19.31 °C
2013-04-09_05:46:55 OWX_Bad T: 19.38 °C
2013-04-09_05:51:55 OWX_Bad T: 19.44 °C
2013-04-09_05:56:55 OWX_Bad T: 19.50 °C
2013-04-09_05:59:59 MAX_Bad_Fenst battery: ok
2013-04-09_05:59:59 MAX_Bad_Fenst onoff: 0
2013-04-09_05:59:59 MAX_Bad battery: ok
2013-04-09_05:59:59 MAX_Bad desiredTemperature: 20.0
2013-04-09_05:59:59 MAX_Bad valveposition: 71
2013-04-09_05:59:59 MAX_Bad temperature: 18.9
2013-04-09_06:01:55 OWX_Bad T: 19.50 °C
2013-04-09_06:00:00 MAX_Bad_Fenst battery: ok
2013-04-09_06:00:00 MAX_Bad_Fenst onoff: 0
2013-04-09_06:00:00 MAX_Bad battery: ok
2013-04-09_06:00:00 MAX_Bad desiredTemperature: 20.0
2013-04-09_06:00:00 MAX_Bad valveposition: 71
2013-04-09_06:00:00 MAX_Bad temperature: 18.9
2013-04-09_06:06:55 OWX_Bad T: 19.56 °C
2013-04-09_06:11:55 OWX_Bad T: 19.62 °C
2013-04-09_06:16:55 OWX_Bad T: 19.62 °C
2013-04-09_06:21:55 OWX_Bad T: 19.69 °C
2013-04-09_06:31:55 OWX_Bad T: 19.69 °C
2013-04-09_06:36:55 OWX_Bad T: 19.75 °C
2013-04-09_06:39:40 MAX_Bad valveposition: 71
2013-04-09_06:39:40 MAX_Bad temperature: 18.9
2013-04-09_06:44:45 MAX_Bad valveposition: 10
2013-04-09_06:44:45 MAX_Bad temperature: 21.3
2013-04-09_06:51:15 HM_Bad deviceMsg: on (to HMLAN)
2013-04-09_06:51:15 HM_Bad deviceMsg: on (to HMLAN)
2013-04-09_06:51:16 HM_Bad level: 100 %
2013-04-09_06:51:16 HM_Bad deviceMsg: on (to HMLAN)
2013-04-09_06:51:55 OWX_Bad T: 19.75 °C
2013-04-09_06:56:55 OWX_Bad T: 19.88 °C
2013-04-09_07:00:23 HM_Bad deviceMsg: off (to HMLAN)
2013-04-09_07:00:23 HM_Bad deviceMsg: off (to HMLAN)
2013-04-09_07:00:24 HM_Bad level: 0 %
2013-04-09_07:00:24 HM_Bad deviceMsg: off (to HMLAN)
2013-04-09_07:01:55 OWX_Bad T: 20.00 °C
2013-04-09_07:06:55 OWX_Bad T: 19.94 °C
2013-04-09_07:11:55 OWX_Bad T: 19.88 °C
2013-04-09_07:16:55 OWX_Bad T: 19.75 °C
2013-04-09_07:21:55 OWX_Bad T: 19.69 °C
2013-04-09_07:26:55 OWX_Bad T: 19.69 °C
2013-04-09_07:31:55 OWX_Bad T: 19.62 °C
2013-04-09_07:35:29 MAX_Bad valveposition: 10
2013-04-09_07:35:29 MAX_Bad temperature: 21.3
2013-04-09_07:36:55 OWX_Bad T: 19.62 °C
2013-04-09_07:40:34 MAX_Bad valveposition: 13
2013-04-09_07:40:34 MAX_Bad temperature: 20.9
2013-04-09_07:41:55 OWX_Bad T: 19.56 °C
2013-04-09_07:45:37 MAX_Bad valveposition: 13
2013-04-09_07:45:37 MAX_Bad temperature: 20.9
2013-04-09_07:50:42 MAX_Bad valveposition: 14
2013-04-09_07:50:42 MAX_Bad temperature: 20.7
2013-04-09_08:00:50 MAX_Bad desiredTemperature: 20.0
2013-04-09_08:00:50 MAX_Bad valveposition: 14
2013-04-09_08:05:54 MAX_Bad desiredTemperature: 18.5
2013-04-09_08:05:54 MAX_Bad valveposition: 0
2013-04-09_08:06:55 OWX_Bad T: 19.56 °C
2013-04-09_08:11:55 OWX_Bad T: 19.62 °C
2013-04-09_08:16:55 OWX_Bad T: 19.56 °C
2013-04-09_08:26:55 OWX_Bad T: 19.56 °C
2013-04-09_08:31:55 OWX_Bad T: 19.50 °C
2013-04-09_08:41:55 OWX_Bad T: 19.50 °C
2013-04-09_08:46:55 OWX_Bad T: 19.44 °C
2013-04-09_09:06:55 OWX_Bad T: 19.44 °C
2013-04-09_09:11:56 OWX_Bad T: 19.38 °C
2013-04-09_09:16:58 MAX_Bad temperature: 20.7
2013-04-09_09:22:02 MAX_Bad valveposition: 0
2013-04-09_09:26:55 OWX_Bad T: 19.38 °C
2013-04-09_09:27:06 MAX_Bad valveposition: 5
2013-04-09_09:27:06 MAX_Bad temperature: 19.6
2013-04-09_09:31:55 OWX_Bad T: 19.31 °C
2013-04-09_09:41:55 OWX_Bad T: 19.31 °C
2013-04-09_09:46:55 OWX_Bad T: 19.25 °C
2013-04-09_09:47:20 MAX_Bad valveposition: 5
2013-04-09_09:47:20 MAX_Bad temperature: 19.6
2013-04-09_09:51:55 OWX_Bad T: 19.31 °C
2013-04-09_09:52:24 MAX_Bad valveposition: 10
2013-04-09_09:52:24 MAX_Bad temperature: 19.2
2013-04-09_09:56:55 OWX_Bad T: 19.25 °C
2013-04-09_10:11:55 OWX_Bad T: 19.25 °C
2013-04-09_10:16:55 OWX_Bad T: 19.19 °C
2013-04-09_10:22:46 MAX_Bad valveposition: 10
2013-04-09_10:22:46 MAX_Bad temperature: 19.2
2013-04-09_10:27:49 MAX_Bad valveposition: 13
2013-04-09_10:27:49 MAX_Bad temperature: 18.9
2013-04-09_10:46:55 OWX_Bad T: 19.19 °C
2013-04-09_10:51:55 OWX_Bad T: 19.25 °C
2013-04-09_10:53:08 MAX_Bad valveposition: 13
2013-04-09_10:53:08 MAX_Bad temperature: 18.9
2013-04-09_10:58:12 MAX_Bad valveposition: 10
2013-04-09_10:58:12 MAX_Bad temperature: 19.3
2013-04-09_11:16:55 OWX_Bad T: 19.25 °C
2013-04-09_11:21:55 OWX_Bad T: 19.19 °C
2013-04-09_11:41:55 OWX_Bad T: 19.19 °C
2013-04-09_11:46:55 OWX_Bad T: 19.12 °C
2013-04-09_11:59:59 OWX_Bad T: 19.12 °C
2013-04-09_11:59:59 MAX_Bad_Fenst battery: ok
2013-04-09_11:59:59 MAX_Bad_Fenst onoff: 0
2013-04-09_11:59:59 MAX_Bad battery: ok
2013-04-09_11:59:59 MAX_Bad desiredTemperature: 18.5
2013-04-09_11:59:59 MAX_Bad valveposition: 10
2013-04-09_11:58:58 MAX_Bad temperature: 19.3
2013-04-09_12:00:00 OWX_Bad T: 19.12 °C
2013-04-09_12:00:00 MAX_Bad_Fenst battery: ok
2013-04-09_12:00:00 MAX_Bad_Fenst onoff: 0
2013-04-09_12:00:00 MAX_Bad battery: ok
2013-04-09_12:00:00 MAX_Bad desiredTemperature: 18.5
2013-04-09_12:00:00 MAX_Bad valveposition: 10
2013-04-09_12:04:02 MAX_Bad temperature: 19.0
2013-04-09_12:09:05 MAX_Bad valveposition: 10
2013-04-09_12:09:05 MAX_Bad temperature: 19.0
2013-04-09_12:11:55 OWX_Bad T: 19.12 °C
2013-04-09_12:14:09 MAX_Bad valveposition: 13
2013-04-09_12:14:09 MAX_Bad temperature: 18.9
2013-04-09_12:16:55 OWX_Bad T: 19.06 °C
2013-04-09_12:41:55 OWX_Bad T: 19.06 °C
2013-04-09_12:46:55 OWX_Bad T: 19.12 °C
2013-04-09_12:51:55 OWX_Bad T: 19.06 °C
2013-04-09_12:56:55 OWX_Bad T: 19.06 °C
2013-04-09_12:59:46 MAX_Bad valveposition: 13
2013-04-09_12:59:46 MAX_Bad temperature: 18.9
2013-04-09_13:01:55 OWX_Bad T: 19.12 °C
2013-04-09_13:04:50 MAX_Bad valveposition: 10
2013-04-09_13:04:50 MAX_Bad temperature: 19.3
2013-04-09_13:06:55 OWX_Bad T: 19.12 °C
2013-04-09_13:09:54 MAX_Bad_Fenst battery: ok
2013-04-09_13:09:54 MAX_Bad_Fenst onoff: 0
2013-04-09_13:09:54 MAX_Bad battery: ok
2013-04-09_13:09:54 MAX_Bad desiredTemperature: 18.5
2013-04-09_13:09:54 MAX_Bad valveposition: 10
2013-04-09_13:09:54 MAX_Bad temperature: 19.3

nach einem shutdown restart sind die werte dann da.

(siehe Anhang / see attachement)

Gruß Joachim

Joachim · 10 April 2013, 15:10:54

Moin @ all,

wahrscheinlich habe ich mich gestern unklar ausgedrückt.

Es fehlt im SVG-Plot der Anfangswert der Abluft, obwohl er im Log vorhanden ist.

2013-04-07_23:56:05 WHR960 ErdWT: 3
2013-04-08_00:00:00 WHR960 Abluft: 17.5 <<<< dieser hier
2013-04-08_00:00:00 WHR960 ErdWT: 3
2013-04-08_00:00:00 WHR960 Fortluft: 6.5
2013-04-08_00:00:00 WHR960 Frischluft: 5
2013-04-08_00:00:00 WHR960 Komf_Temp: 24
2013-04-08_00:00:00 WHR960 Zuluft: 16
2013-04-08_00:01:18 WHR960 ErdWT: 3.5

Im Plot fehlt damit der entsprechende Bereich.

(siehe Anhang / see attachement)

das ganze ist für alle die helfen möchten mit den Dateien der im ersten Post angehängten SVG.zip nachstellbar.

Ich habe versucht, den Fehler zu finden, und einige Zusatzlogeinträge in die 01_FHEMWEB.pm und das 92_Filelog.pm eingebaut.
Es werden von FHEMWEB die richtigen Daten abgefordert:
2013.04.10 14:51:52 3: FHEMWEB Zeile 1766 from 2013-04-08
2013.04.10 14:51:52 3: FHEMWEB Zeile 1770 to 2013-04-09
kommt auch so im Filelog an, allerdings wird nicht richtig geliefert.
2013.04.10 14:51:52 3: Filelog Zeile 191 from 2013-04-08
2013.04.10 14:51:52 3: Filelog Zeile 350 2013-04-08_00:00:00 WHR960 ErdWT: 3
2013.04.10 14:51:52 3: Filelog Zeile 350 2013-04-08_00:00:00 WHR960 Fortluft: 6.5
2013.04.10 14:51:52 3: Filelog Zeile 350 2013-04-08_00:00:00 WHR960 Frischluft: 5
2013.04.10 14:51:52 3: Filelog Zeile 350 2013-04-08_00:00:00 WHR960 Komf_Temp: 24
2013.04.10 14:51:52 3: Filelog Zeile 350 2013-04-08_00:00:00 WHR960 Zuluft: 16
2013.04.10 14:51:52 3: Filelog Zeile 350 2013-04-08_00:01:18 WHR960 ErdWT: 3.5

Es fehlt die Zeile
2013.04.10 14:51:52 3: Filelog Zeile 350 2013-04-08_00:00:00 WHR960 Abluft: 17.5

Leider habe ich den RESCAN Block im Filelog nicht begriffen, und komme nicht weiter,
nachmeinem Verständniss müsste in Zeile 279 der Fehlende Wert gefunden werden.

Code Auswählen


267 RESCAN:
268   for(;;) {
269    my $l;
270 
271    if($rescan) {
272      last if($rescanIdx<1 || !$rescanNum);
273      $l = $rescanArr[$rescanIdx--];
274    } else {
275      $l = <$ifh>;
276      last if(!$l);
277    }
278
[color=red]279    next if($l lt $from && !$rescan);[/color]
280    last if($l gt $to);
281    my @fld = split("[ \r\n]+", $l);     # 40% CPU

Gruß Joachim

Joachim · 11 April 2013, 20:11:56

So, durch gezieltes loggen den Fehler eingekreist, aber Finden und Beheben sind zweierlei.

Der Fehler kann mit den im ersten Post angehängten Dateien (SVG.zip) auf jedem FHEM-System nachgestellt werden.
Der Fehler befindet sich im 92_FileLog.pm in der sub seekTo($$$$). (Was da genau passiert ist mir allerdings zu hoch)
Im Anhang eine mit Zusatzlogausgaben gewürzte 92_FileLog.pm
Logauszug:

Code Auswählen


2013.04.11 19:55:35 3: Filelog Zeile 194 startwert von FHEMWEB 2013-04-08
2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-06_13:38:05 WHR960 ErdWT: 8

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-08_00:26:24 WHR960 ErdWT: 3

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-07_05:05:53 WHR960 ErdWT: 1.5

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-07_15:06:23 WHR960 ErdWT: 7

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-07_20:14:29 WHR960 ErdWT: 6.5

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-07_22:20:20 WHR960 Fortluft: 8

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-07_23:40:53 WHR960 Fortluft: 7

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-08_00:00:00 WHR960 Frischluft: 5

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-07_23:56:05 WHR960 ErdWT: 3

2013.04.11 19:55:35 3: Filelog Zeile 467 Wertesuche            2013-04-08_00:00:00 WHR960 ErdWT: 3

2013.04.11 19:55:35 3: Filelog Zeile 346 von seekto geliefert 2013-04-08_00:00:00 WHR960 ErdWT: 3
2013.04.11 19:55:35 3: Filelog Zeile 346 von seekto geliefert 2013-04-08_00:00:00 WHR960 Fortluft: 6.5
2013.04.11 19:55:35 3: Filelog Zeile 346 von seekto geliefert 2013-04-08_00:00:00 WHR960 Frischluft: 5
2013.04.11 19:55:35 3: Filelog Zeile 346 von seekto geliefert 2013-04-08_00:00:00 WHR960 Komf_Temp: 24

Bei der Wertesuche wird der erste 00:00:00 Uhr Wert unterschlagen

2013-04-07_23:56:05 WHR960 ErdWT: 3
2013-04-08_00:00:00 WHR960 Abluft: 17.5 <<<< dieser hier
2013-04-08_00:00:00 WHR960 ErdWT: 3
2013-04-08_00:00:00 WHR960 Fortluft: 6.5
2013-04-08_00:00:00 WHR960 Frischluft: 5

Gruß Joachim

rudolfkoenig · 13 April 2013, 13:08:59

Ich habe es versucht nachzustellen, bei mir funktioniert das Plot so wie es soll (00:00:00 wird angezeigt).

Kannst Du mir bitte folgende Daten hier anhaengen:
- Definition der FileLog und der Weblink aus fhem.cfg, samt allen Attributen.
- gplot Datei
- soviele Zeilen aus der Logdatei, dass man es nachstellen kann. Bitte vorher pruefen, ob das Problem mit dem Ausschnitt der Logdatei auftritt.

Gruss,
Rudi

Joachim · 13 April 2013, 16:05:14

Moin Rudi,

hier die gewünschten Daten, vorher in einer jungfäulichen virtuellen Linux Mint (aufgeblasenes Ubuntu) Umgebung getestet, Fhem 5.4 mit allen Updates bis heute.

- Definition der FileLog und der Weblink aus fhem.cfg, samt allen Attributen.

Code Auswählen


define FileLog_WHR960 FileLog ./log/WHR960-%Y-%m.log WHR960
attr FileLog_WHR960 logtype text
attr FileLog_WHR960 room Logs

define weblink_WHR960 weblink fileplot FileLog_WHR960:WHR960:CURRENT
attr weblink_WHR960 plotsize 800,270
attr weblink_WHR960 room Keller

- gplot Datei
im Anhang

- soviele Zeilen aus der Logdatei, dass man es nachstellen kann. Bitte vorher pruefen, ob das Problem mit dem Ausschnitt der Logdatei auftritt.
im Anhang

Gruß Joachim

Joachim · 14 April 2013, 10:05:04

Moin Rudi,

Ich habe den Fehler weiter eingekreist indem ich seekTo mit jeder Menge Logausgeben gewürzt habe:

Code Auswählen


seekTo($$$$)
{
  my ($fname, $fh, $hash, $ts) = @_;
	Log 3, "Filelog Zeile 445 test"; # Debugausgabe
  # If its cached
  if($hash->{pos} && $hash->{pos}{"$fname:$ts"}) {
    $fh->seek($hash->{pos}{"$fname:$ts"}, 0);
    Log 3, "Filelog Zeile 449 test"; # Debugausgabe
    return;
  }
	Log 3, "Filelog Zeile 452 test"; # Debugausgabe
  $fh->seek(0, 2); # Go to the end
  my $upper = $fh->tell;

  my ($lower, $next, $last) = (0, $upper/2, 0);
  my $div = 2;
  while() {                                             # Binary search
    $fh->seek($next, 0);
    my $data = <$fh>;
    Log 3, "Filelog Zeile 461 data $data"; # Debugausgabe
    if(!$data) {
      $last = $next;
      Log 3, "Filelog Zeile 464 test"; # Debugausgabe
      last;
    }
    Log 3, "Filelog Zeile 467 test"; # Debugausgabe
    if($data !~ m/^\d\d\d\d-\d\d-\d\d_\d\d:\d\d:\d\d /o) {
      $next = $fh->tell;
      Log 3, "Filelog Zeile 470 next $next"; # Debugausgabe
      Log 3, "Filelog Zeile 471 last $last"; # Debugausgabe
      $data = <$fh>;
			Log 3, "Filelog Zeile 473 Wertesuche            $data"; # Debugausgabe
      if(!$data) {
        $last = $next;
        Log 3, "Filelog Zeile 476 test"; # Debugausgabe
        last;
      }

      # If the second line is longer then the first,
      # binary search will never get it: 
      if($next eq $last && $data ge $ts && $div < 8192 && $next < 1024) {
        $last = 0;
        $div *= 2;
        Log 3, "Filelog Zeile 485 test"; # Debugausgabe
      }
    }
    Log 3, "Filelog Zeile 488 test"; # Debugausgabe
    if($next eq $last) {
      $fh->seek($next, 0);
      Log 3, "Filelog Zeile 491 test"; # Debugausgabe
      last;
    }
		Log 3, "Filelog Zeile 494 test"; # Debugausgabe
    $last = $next;
    Log 3, "Filelog Zeile 496 last $last"; # Debugausgabe
    if(!$data || $data lt $ts) {
      ($lower, $next) = ($next, int(($next+$upper)/$div));
      Log 3, "Filelog Zeile 499 next $next lower $lower last $last div $div upper $upper"; # Debugausgabe
    } else {
      ($upper, $next) = ($next, int(($lower+$next)/$div));
      Log 3, "Filelog Zeile 501 next $next upper $upper last $last div $div lower $lower"; # Debugausgabe
      Log 3, "Filelog Zeile 502 test"; # Debugausgabe
    }
  }
  $hash->{pos}{"$fname:$ts"} = $last;

}

1;

dabei ist folgendes Log herausgekommen:

Zitat2013.04.14 09:27:11 3: Filelog Zeile 467 test
2013.04.14 09:27:11 3: Filelog Zeile 470 next 58031
2013.04.14 09:27:11 3: Filelog Zeile 471 last 57714
2013.04.14 09:27:11 3: Filelog Zeile 473 Wertesuche 2013-04-08_00:00:00 WHR960 Frischluft: 5

2013.04.14 09:27:11 3: Filelog Zeile 488 test
2013.04.14 09:27:11 3: Filelog Zeile 494 test
2013.04.14 09:27:11 3: Filelog Zeile 496 last 58031
2013.04.14 09:27:11 3: Filelog Zeile 501 next 57872 upper 58031 last 58031 div 2 lower 57714
2013.04.14 09:27:11 3: Filelog Zeile 502 test
2013.04.14 09:27:11 3: Filelog Zeile 461 data ft: 5

2013.04.14 09:27:11 3: Filelog Zeile 467 test
2013.04.14 09:27:11 3: Filelog Zeile 470 next 57878
2013.04.14 09:27:11 3: Filelog Zeile 471 last 58031
2013.04.14 09:27:11 3: Filelog Zeile 473 Wertesuche 2013-04-07_23:56:05 WHR960 ErdWT: 3

2013.04.14 09:27:11 3: Filelog Zeile 488 test
2013.04.14 09:27:11 3: Filelog Zeile 494 test
2013.04.14 09:27:11 3: Filelog Zeile 496 last 57878
2013.04.14 09:27:11 3: Filelog Zeile 499 next 57954 lower 57878 last 57878 div 2 upper 58031
2013.04.14 09:27:11 3: Filelog Zeile 461 data 2013-04-08_00:00:00 WHR960 ErdWT: 3

2013.04.14 09:27:11 3: Filelog Zeile 467 test
2013.04.14 09:27:11 3: Filelog Zeile 488 test
2013.04.14 09:27:11 3: Filelog Zeile 494 test
2013.04.14 09:27:11 3: Filelog Zeile 496 last 57954
2013.04.14 09:27:11 3: Filelog Zeile 501 next 57916 upper 57954 last 57954 div 2 lower 57878
2013.04.14 09:27:11 3: Filelog Zeile 502 test
2013.04.14 09:27:11 3: Filelog Zeile 461 data 13-04-08_00:00:00 WHR960 Abluft: 17.5

2013.04.14 09:27:11 3: Filelog Zeile 467 test
2013.04.14 09:27:11 3: Filelog Zeile 470 next 57954
2013.04.14 09:27:11 3: Filelog Zeile 471 last 57954
2013.04.14 09:27:11 3: Filelog Zeile 473 Wertesuche 2013-04-08_00:00:00 WHR960 ErdWT: 3

2013.04.14 09:27:11 3: Filelog Zeile 488 test
2013.04.14 09:27:11 3: Filelog Zeile 491 test
2013.04.14 09:27:11 3: Filelog Zeile 346 von seekto geliefert 2013-04-08_00:00:00 WHR960 ErdWT: 3

Wie man sieht, landet die binäre Suche nicht ganz richtig (es fehlt die 20), und der fehlende Wert wird dadurch ignoriert.
Der Fehler entsteht dadurch, dass die einzelnen Zeilen nicht gleich lang sind, der Dateizeiger aber genau in die
Mitte gesetzt wird.
Mir fehlen die Perl-Kenntnisse, um das zu lösen.

Gruß Joachim

rudolfkoenig · 15 April 2013, 18:19:43

Danke fuer die Daten, habs nachgestellt, gefixed und eingecheckt.

Eigentlich wurde das Problem schon frueher gefixed (2009-01-02), aber damals auf Dateiposition < 1024 Byte beschraenkt, weiss aber nicht mehr wieso. Ich habe jetzt diese Beschraenkung entfernt.

Joachim · 15 April 2013, 20:00:40

Super Rudi,

wenn Du jetzt noch den angehängten Patch in 01_FHEMWEB.pm einfügst, dann wird auch das Ende des Plots komplett angezeigt.

(siehe Anhang / see attachement)

Kannst du an dem Filelog WHR960-2013-04.log testen

Gruß Joachim

rudolfkoenig · 16 April 2013, 17:16:57

Hallo Joachim,

ich habe es (bzw. meine Variante davon :) eingebaut, obwohl eigentlich unsauber ist.

Sauber waere entweder nur die Werte vom aktuellen Tag anzuzeigen (wie es bisher war), oder den letzten Wert vom Vortag und ersten vom morgigen Tag in die Berechnung mit einzubeziehen, und den Wert um Mitternacht interpolieren. Letzteres erfordert aber Aenderung in FileLog und im SVG, und das Feature ist mir wg. dem vmtl. erheblichen zusaetzlichen Code nicht wirklich Wert.

Gruss,
Rudi

Joachim · 16 April 2013, 18:14:49

Moin Rudi,

vielen Dank ersteinmal.

Das es eigentlich unsauber ist, weiß ich, aber mir ist nichts besseres eingefallen, um den Plot auch am Ende
der Grafik darzustellen, vielleicht fällt mir ja noch was besseres ein.

Der Grund für diesen Einbau ist, dass bei Event on Change mit addLog, und einem Umbau des FileLogs, an dem ich am
basteln bin, um 23:59:59 und um 0:00:00 ein Wert geschrieben werden muß um einen Startwert/Endwert für den Plot zu
haben, so reicht einer.
Sowie ich meinen Filelog-Umbau soweit habe, dass er aus dem alpha-Status heraus ist, melde ich mich.
Jetzt muss ich ersteinmal den nächsten Fehler in meinem Umbau finden.

Gruß Joachim