Fehler im Log

[raspklaus]

Hallo zusammen,

bin gerade dabei mal das Log durchzugehen und Probleme zu beseitigen.

Ich habe laut Wiki meine 99_MyUtils.pm angelegt und mit diversen Routinen befüllt:

Code Auswählen Erweitern

##############################################
# $Id: 99_myUtils.pm 5555 2014-08-27 14:13:59Z xxxxxxxxx $
package main;
use strict;
use warnings;
use POSIX;
use Time::Local;
use HTML::Entities;

sub
myUtils_Initialize($$)
{
my ($hash) = @_;
}

sub
Abfalltermine ($)
{
  my ($Ereignis) = @_;
  my @Ereignisarray = split(/.*:\s/,$Ereignis);
  my $Ereignisteil1 = $Ereignisarray[1];
  my @uids=split(/;/,$Ereignisteil1);
  my $t  = time;
  my $dtPapier = '';
  my $dtGelberSack = '';
  my $dtRest = '';
  my $dtBio = '';
  my $dayDiff = 0;
  my $dtBeda = '';
   foreach my $uid (@uids) {
    my $Kalendertext = fhem("get Abfall summary $uid");
    if ($Kalendertext =~ /Papiertonne/) {
        my $dt = fhem("get Abfall start $uid");
        my @SplitDt = split(/ /,$dt);
        my @SplitDate = split(/\./,$SplitDt[0]);
        my $eventDate = timelocal(0,0,0,$SplitDate[0],$SplitDate[1]-1,$SplitDate[2]);
        if ($dtPapier eq '' || ($eventDate < $dtPapier && $eventDate > $t))
        {
          $dtPapier = $eventDate;
          Log(3, $dtPapier);
        }
    };
if ($Kalendertext =~ /Gelber Sack/) {
        my $dt = fhem("get Abfall start $uid");
        my @SplitDt = split(/ /,$dt);
        my @SplitDate = split(/\./,$SplitDt[0]);
        my $eventDate = timelocal(0,0,0,$SplitDate[0],$SplitDate[1]-1,$SplitDate[2]);
        if ($dtGelberSack eq '' || ($eventDate < $dtGelberSack && $eventDate > $t))
        {
          $dtGelberSack  = $eventDate;
        }
    };
    if ($Kalendertext =~ /Restmüll/) {
        my $dt = fhem("get Abfall start $uid");
        my @SplitDt = split(/ /,$dt);
        my @SplitDate = split(/\./,$SplitDt[0]);
        my $eventDate = timelocal(0,0,0,$SplitDate[0],$SplitDate[1]-1,$SplitDate[2]);
        if ($dtRest eq '' || ($eventDate < $dtRest && $eventDate > $t))
        {
          $dtRest = $eventDate;
        }
    };
    if ($Kalendertext =~ /Bio/) {
        my $dt = fhem("get Abfall start $uid");
        my @SplitDt = split(/ /,$dt);
        my @SplitDate = split(/\./,$SplitDt[0]);
        my $eventDate = timelocal(0,0,0,$SplitDate[0],$SplitDate[1]-1,$SplitDate[2]);
        if ($dtBio eq '' || ($eventDate < $dtBio && $eventDate > $t))
        {
          $dtBio  = $eventDate;
        }
    };
    if ($Kalendertext =~ /Pater Beda/) {
        my $dt = fhem("get Abfall start $uid");
        my @SplitDt = split(/ /,$dt);
        my @SplitDate = split(/\./,$SplitDt[0]);
        my $eventDate = timelocal(0,0,0,$SplitDate[0],$SplitDate[1]-1,$SplitDate[2]);
        if ($dtBeda eq '' || ($eventDate < $dtBeda && $eventDate > $t))
        {
          $dtBeda = $eventDate;
        }
    };   

   
  $dayDiff = floor(($dtPapier - $t) / 60 / 60 / 24 + 1);
  if ($dayDiff >= 0) {
    fhem("set Papiertonne $dayDiff");
  }
  $dayDiff = floor(($dtGelberSack - $t) / 60 / 60 / 24 + 1);
  if ($dayDiff >= 0) {
    fhem("set GelberSack $dayDiff");
  }
  $dayDiff = floor(($dtRest - $t) / 60 / 60 / 24 + 1);
  if ($dayDiff >= 0) {
    fhem("set Restmuell $dayDiff");
  }
  $dayDiff = floor(($dtBio - $t) / 60 / 60 / 24 + 1);
  if ($dayDiff >= 0) {
    fhem("set Bio $dayDiff");
  }
  $dayDiff = floor(($dtBeda - $t) / 60 / 60 / 24 + 1);
  if ($dayDiff >= 0) {
    fhem("set Pater_Beda $dayDiff");
  }
  }
}

#### Log-abriss vermeiden
# called by
# define addLog notify addLog {addLog("ez_Aussensensor","state");addLog("ez_FHT","actuator");\
#               addLog("MunichWeather","humidity");addLog("MunichWeather","pressure");\
#               addLog("MunichWeather","temperature");addLog("MunichWeather","wind_chill");}
# define a_midnight1 at *23:59 trigger addLog
# define a_midnight2 at *00:01 trigger addLog
sub
addLog($$) {
  my ($logdevice, $reading) = @_; # device and reading to be used
  my $logentry = ReadingsVal($logdevice,$reading,"addLog: invalid reading");
  if ($reading =~ m,state,i) {
    fhem "trigger $logdevice $logentry   << addLog";
  } else {
    fhem "trigger $logdevice $reading: $logentry   << addLog";
  }
}

sub BM_MotionHandling($$){
my($device, $event) = @_;
return if($attr{$device}{subType} ne "motionDetector");

my $ResetAT = $device."_Reset";
if($event eq "motion") {
   # Bewegung erkannt, erstelle AT um Status wieder zurückzusetzen
         if (defined($defs{$ResetAT})) {
           fhem "modify ".$ResetAT." +00:05:00 {BM_MotionHandling(\"$device\", \"scanning\")}";
         } else {
         fhem "define ".$ResetAT." at +00:05:00 {BM_MotionHandling(\"$device\", \"scanning\")}";
         }
} elsif($event eq "scanning") {
   # Status des Devices wieder zurücksetzen
   readingsSingleUpdate($defs{$device}, "state", $event, 1);
}
}

###################################################
###     Spritpreisübersicht - Farbsortierung    ###
###################################################

sub Werte($$) {
  my ($name, $wert) = @_;
# Log(3,"$name $wert");
  if ($name eq "Diesel") {
    return 'style="color:red"' if($wert >= 1.39);
    return 'style="color:blue"' if(($wert >= 1.33) && ($wert < 1.39));
    return 'style="color:green;;font-weight:bold"' if($wert <= 1.32);
  }elsif ($name eq "SuperE10") {
    return 'style="color:crimson"' if($wert >= 1.70);
    return 'style="color:yellow"' if(($wert >= 1.55) && ($wert < 1.70));
    return 'style="color:lightgreen;;font-weight:bold"' if($wert < 1.55);
  }elsif ($name eq "SuperE5") {
    return 'style="color:red"' if($wert >= 1.59);
    return 'style="color:blue"' if(($wert >= 1.49) && ($wert < 1.59));
    return 'style="color:green;;font-weight:bold"' if($wert <= 1.48);
  } 
}

sub time2dec($){
  my ($h,$m,$s) = split(":", shift);
  $m = 0 if(!$m);
  $s = 0 if(!$s);
  my $t  = $m * 60;
     $t += $s;
     $t /= 3600;
     $t += $h;
  return ($t)
}

sub dec2hms($){
  my ($t) = @_;
  my $h = int($t);
  my $r = ($t - $h)*3600;
  my $m = int($r/60);
  my $s = $r - $m*60;
  return sprintf("%02d:%02d:%02d",$h,$m,$s);
}

sub
wrapLine($$)
{
  my ($string, $maxLength) = @_;
  $string = decode_entities($string);
my @stringParts = split(/ /, $string);
  my $actRowLength = 0;
  my $resultString = '';
  while (scalar(@stringParts) > 0) {
  my $tempString = shift @stringParts;
    if ($actRowLength > 0)
    {
    if (($actRowLength + length($tempString)) > $maxLength)
      {
      $actRowLength = 0;
        $resultString .= '<br>';
      }
    }
    $resultString .= $tempString;
    $actRowLength += length($tempString);
    if (scalar(@stringParts) > 0)
    {
    $resultString .= ' ';
    $actRowLength += 1;
    }
  }
  if ($resultString eq '')
  {
  return ' ';
  }
  else
  {
  return $resultString;
  }
}


# Weitere Subroutinen


1;


Funktioniert auch alles, aber ich bekomme beim Start im Log folgende Einträge:

Code Auswählen Erweitern

Subroutine myUtils_Initialize redefined at ./FHEM/99_MyUtils.pm line 12, <$fh> line 8.
Subroutine Abfalltermine redefined at ./FHEM/99_MyUtils.pm line 18, <$fh> line 8.
Subroutine addLog redefined at ./FHEM/99_MyUtils.pm line 116, <$fh> line 8.
Subroutine BM_MotionHandling redefined at ./FHEM/99_MyUtils.pm line 126, <$fh> line 8.
Subroutine Werte redefined at ./FHEM/99_MyUtils.pm line 148, <$fh> line 8.
Subroutine time2dec redefined at ./FHEM/99_MyUtils.pm line 166, <$fh> line 8.
Subroutine dec2hms redefined at ./FHEM/99_MyUtils.pm line 177, <$fh> line 8.
Subroutine wrapLine redefined at ./FHEM/99_MyUtils.pm line 188, <$fh> line 8.
2015.10.27 13:17:27 1: PERL WARNING: Use of uninitialized value $Ereignisteil1 in split at ./FHEM/99_MyUtils.pm line 22.


Doppelte Definitionen schliesse ich aus. Als Perl Anfänger finde ich keine Möglichkeit diese Meldungen wegzubringen

[viegener]

Die Meldungen treten normalerweise auf, wenn eine Datei mit perl-Definitionen mehrfach geladen wird (oder eben Doppeldefinition). Kann es sein, dass Du 2 Dateien mit diesen Definitionen hast, eine die z.B. 99_MyUtils.pm und eine die 99_myUtils.pm heisst?

Johannes

[raspklaus]

Nein, ich habe nur eine 99_MyUtils.pm

Ich habe auch mit:

Code Auswählen Erweitern

grep -r -i 'myUtils_Initialize' ./

gesucht und nur:

Code Auswählen Erweitern

./fhem/FHEM/99_MyUtils.pm:myUtils_Initialize($$)
./fhem/FHEM/myUtilsTemplate.pm:myUtils_Initialize($$)

gefunden. Das Problem muss also irgendwo anders liegen.

[marvin78]

Wirklich beim Start? Diese Meldungen im Log kommen auch, wenn man die myUtils über das Frontend editiert und speichert. Das bewirkt einen automatischen reload.

[raspklaus]

Bei einem reload kommt:

Code Auswählen Erweitern

2015.10.29 14:17:23 1: PERL WARNING: Subroutine myUtils_Initialize redefined at ./FHEM/99_MyUtils.pm line 12.
2015.10.29 14:17:23 1: PERL WARNING: Subroutine Abfalltermine redefined at ./FHEM/99_MyUtils.pm line 18.
2015.10.29 14:17:23 1: PERL WARNING: Subroutine addLog redefined at ./FHEM/99_MyUtils.pm line 116.
2015.10.29 14:17:23 1: PERL WARNING: Subroutine BM_MotionHandling redefined at ./FHEM/99_MyUtils.pm line 126.
2015.10.29 14:17:23 1: PERL WARNING: Subroutine Werte redefined at ./FHEM/99_MyUtils.pm line 148.
2015.10.29 14:17:23 1: PERL WARNING: Subroutine time2dec redefined at ./FHEM/99_MyUtils.pm line 166.
2015.10.29 14:17:23 1: PERL WARNING: Subroutine dec2hms redefined at ./FHEM/99_MyUtils.pm line 177.
2015.10.29 14:17:23 1: PERL WARNING: Subroutine wrapLine redefined at ./FHEM/99_MyUtils.pm line 188.

also etwas abgewandelt

Wo kann ich bei der Fehlersuche noch ansetzen ?

Manchmal kommt es mir so vor als würde die 99_MyUtils.pm doppelt geladen

[viegener]

Das ist sicher nicht ganz einfach und Du hast recht, die Meldung war mir auch als komisch aufgefallen, es sieht quasi so aus, also ob das über einen dynamischen Abschnitt / eval neu geladen wird.

Mögliche Versuche:
- Verbose 5 einschalten um mehr Infos zu erhalten wann / von wo es passiert
- Textsuche im FHEM-Verzeichnis nach 99_MyUtils
- 99_MyUtils nach 99_SomeUtils umbenennen und schauen ob es dabei bleibt.
- Demo-Config laden und schauen, ob es wieder passiert
- leere Config laden und schauen, ob es wieder passiert
- Aus dem FHEM-Verzeichnis alle Dateien entfernen, die nicht Standard sind

Hinweis: Alles nach einem möglichst vollständigen Backup der Installation, damit man bei Änderungen wieder zurückgehen kann

Anmerkung: Grundsätzlich ist es vermutlich eher unschön als problematisch aber das ist ja nie sicher 

Johannes

[raspklaus]

Ich habe ja noch zwei Testsysteme. Auf dem einen war nichts modifiziert, nur fhem update gefahren. Ich hatte bei einem Neustart keine Fehlermeldungen. Dann habe ich die 99_MyUtils.pm auf dieses System kopiert und einen  Restart gemacht.

Nun sind die Meldungen im Log auch auf diesem System.

Und nun ??

Mit verbose 5 hier das Log

Code Auswählen Erweitern

2015.10.29 21:15:05 5: Initializing Type Library:
2015.10.29 21:15:05 1: Including fhem.cfg
2015.10.29 21:15:05 5: Cmd: >attr global userattr cmdIcon devStateIcon devStateStyle icon sortby webCmd widgetOverride<
2015.10.29 21:15:05 5: Cmd: >attr global autoload_undefined_devices 1<
2015.10.29 21:15:05 5: Cmd: >attr global holiday2we Bayern<
2015.10.29 21:15:05 5: Cmd: >attr global latitude 50.008468<
2015.10.29 21:15:05 5: Cmd: >attr global logfile ./log/fhem-%Y-%m.log<
2015.10.29 21:15:05 5: Cmd: >attr global longitude 9.147183<
2015.10.29 21:15:05 5: Cmd: >attr global modpath .<
2015.10.29 21:15:05 5: Loading ./FHEM/99_MyUtils.pm
Subroutine myUtils_Initialize redefined at ./FHEM/99_MyUtils.pm line 12, <$fh> line 7.
Subroutine Abfalltermine redefined at ./FHEM/99_MyUtils.pm line 18, <$fh> line 7.
Subroutine addLog redefined at ./FHEM/99_MyUtils.pm line 116, <$fh> line 7.
Subroutine BM_MotionHandling redefined at ./FHEM/99_MyUtils.pm line 126, <$fh> line 7.
Subroutine Werte redefined at ./FHEM/99_MyUtils.pm line 148, <$fh> line 7.
Subroutine time2dec redefined at ./FHEM/99_MyUtils.pm line 166, <$fh> line 7.
Subroutine dec2hms redefined at ./FHEM/99_MyUtils.pm line 177, <$fh> line 7.
Subroutine wrapLine redefined at ./FHEM/99_MyUtils.pm line 188, <$fh> line 7.
2015.10.29 21:15:05 5: Cmd: >attr global motd none<
2015.10.29 21:15:05 5: Cmd: >attr global room Wohnzimmer<
2015.10.29 21:15:05 5: Cmd: >attr global sendStatistics manually<
2015.10.29 21:15:05 5: Cmd: >attr global statefile ./log/fhem.save<
2015.10.29 21:15:05 5: Cmd: >attr global uniqueID ./FHEM/FhemUtils/uniqueID<
2015.10.29 21:15:05 5: Cmd: >attr global verbose 5<
2015.10.29 21:15:05 5: Cmd: >define fhemstart_fertig notify global:INITIALIZED attr global motd none<
2015.10.29 21:15:05 5: Loading ./FHEM/91_notify.pm
2015.10.29 21:15:05 5: Cmd: >define WEB FHEMWEB 8083 global<
2015.10.29 21:15:05 5: Loading ./FHEM/01_FHEMWEB.pm
2015.10.29 21:15:06 3: WEB: port 8083 opened
2015.10.29 21:15:06 5: Cmd: >attr WEB JavaScripts codemirror/fhem_codemirror.js<
2015.10.29 21:15:06 5: Cmd: >attr WEB codemirrorParam { "theme":"blackboard", "lineNumbers":true }<
2015.10.29 21:15:06 5: Cmd: >attr WEB hiddenroom save,Unsorted,Select style,Commandref,Remote doc,CUL_TX,AlarmRoom<
2015.10.29 21:15:06 5: Cmd: >attr WEB menuEntries restart,cmd=shutdown+restart,update,cmd=update,updatecheck,cmd=update+check<
2015.10.29 21:15:06 5: Cmd: >attr WEB refresh 60<
2015.10.29 21:15:06 5: Cmd: >attr WEB roomIcons Sicherheit:security KS300:weather_station Kalender:time_calendar FHEM:system_fhem Energie:time_graph Garten:scene_garden B�ro:scene_office Eingang:fts_door_open Haus:control_all_on_off Garage:fts_garage Everything:it_i-net Gartenhaus:scene_summerhouse Terasse:scene_terrace Serverraum:it_nas Schlafzimmer:scene_sleeping Wohnzimmer:scene_livingroom M�lltonnenraum:scene_storeroom Keller:scene_storeroom WWW_Router:scene_hall Kinderzimmer:scene_childs_room System:it_nas Weihnacht:christmas_tree Klima:scene_day Sonos:icoSONOS<
2015.10.29 21:15:06 5: Cmd: >attr WEB stylesheetPrefix dark<
2015.10.29 21:15:06 5: Cmd: >define WEBphone FHEMWEB 8084 global<
2015.10.29 21:15:06 3: WEBphone: port 8084 opened
2015.10.29 21:15:06 5: Cmd: >attr WEBphone hiddenroom AlarmRoom<
2015.10.29 21:15:06 5: Cmd: >attr WEBphone stylesheetPrefix smallscreen<
2015.10.29 21:15:06 5: Cmd: >define WEBtablet FHEMWEB 8085 global<
2015.10.29 21:15:06 3: WEBtablet: port 8085 opened
2015.10.29 21:15:06 5: Cmd: >attr WEBtablet hiddenroom AlarmRoom<
2015.10.29 21:15:06 5: Cmd: >attr WEBtablet stylesheetPrefix touchpad<
2015.10.29 21:15:06 5: Cmd: >define Logfile FileLog ./log/fhem-%Y-%m.log fakelog<
2015.10.29 21:15:06 5: Loading ./FHEM/92_FileLog.pm
2015.10.29 21:15:07 5: Cmd: >define autocreate autocreate<
2015.10.29 21:15:07 5: Loading ./FHEM/98_autocreate.pm
2015.10.29 21:15:07 5: Cmd: >attr autocreate autosave 1<
2015.10.29 21:15:07 5: Cmd: >attr autocreate devStateIcon disabled:ios-off:on active:ios-on-blue:off<
2015.10.29 21:15:07 5: Cmd: >attr autocreate filelog ./log/%NAME-%Y-%m.log<
2015.10.29 21:15:07 5: Cmd: >attr autocreate weblink 1<
2015.10.29 21:15:07 5: Cmd: >attr autocreate weblink_room Plots<
2015.10.29 21:15:07 5: Cmd: >define eventTypes eventTypes ./log/eventTypes.txt<
2015.10.29 21:15:07 5: Loading ./FHEM/91_eventTypes.pm
2015.10.29 21:15:07 2: eventTypes: loaded 463 events from ./log/eventTypes.txt
2015.10.29 21:15:07 5: Cmd: >define initialUsbCheck notify global:INITIALIZED usb create<
2015.10.29 21:15:07 1: Including ./log/fhem.save
2015.10.29 21:15:07 5: Cmd: >setstate Logfile active<
2015.10.29 21:15:07 5: Cmd: >setstate autocreate active<
2015.10.29 21:15:07 5: Cmd: >setstate eventTypes active<
2015.10.29 21:15:07 5: Cmd: >setstate fhemstart_fertig 2015-10-29 20:05:38<
2015.10.29 21:15:07 5: Cmd: >setstate fhemstart_fertig 2015-10-29 20:05:33 state active<
2015.10.29 21:15:07 5: Cmd: >setstate global <no definition><
2015.10.29 21:15:07 5: Cmd: >setstate initialUsbCheck 2015-10-29 20:05:38<
2015.10.29 21:15:07 5: Cmd: >setstate initialUsbCheck 2015-10-29 20:05:35 state active<
2015.10.29 21:15:07 5: Triggering global (1 changes)
2015.10.29 21:15:07 5: Notify loop for global INITIALIZED
2015.10.29 21:15:07 5: Triggering fhemstart_fertig
2015.10.29 21:15:07 4: fhemstart_fertig exec attr global motd none
2015.10.29 21:15:07 5: Cmd: >attr global motd none<
2015.10.29 21:15:07 5: Triggering global (2 changes)
2015.10.29 21:15:07 5: Triggering initialUsbCheck
2015.10.29 21:15:07 4: initialUsbCheck exec usb create
2015.10.29 21:15:07 5: Cmd: >usb create<
2015.10.29 21:15:07 1: usb create starting
2015.10.29 21:15:09 4: ### ttyAMA0: checking if it is a CUL
2015.10.29 21:15:09 3: Probing CUL device /dev/ttyAMA0
2015.10.29 21:15:09 3: Can't open /dev/ttyAMA0: Permission denied
2015.10.29 21:15:09 4: cannot open the device
2015.10.29 21:15:09 1: usb create end
2015.10.29 21:15:09 0: Featurelevel: 5.6
2015.10.29 21:15:09 0: Server started with 9 defined entities (version $Id: fhem.pl 9695 2015-10-26 19:19:05Z rudolfkoenig $, os linux, user fhem, pid 2627)
2015.10.29 21:15:09 4: Connection accepted from FHEMWEB:192.200.100.81:63385
2015.10.29 21:15:10 4: FHEMWEB:192.200.100.81:63385 GET /fhem?XHR=1&inform=type=status;filter=;since=1446149674.19;fmt=JSON&timestamp=1446149673367; BUFLEN:0
2015.10.29 21:15:10 4: Connection accepted from FHEMWEB:192.200.100.81:63388
2015.10.29 21:15:12 4: Connection closed for FHEMWEB:192.200.100.81:63388: EOF

[viegener]

Ich kanns noch nicht wirklich erklären, aber benenne doch mal Deine Datei in den korrekten Namen 99 myUtils.pm also auch mit den richtigen Gross-/Klein-Buchstaben, bei mir tauchen die Meldungen dann nicht mehr auf.

Ich denke Dein Problem liegt daran, dass Name der Datei MyUtils und enthaltene Initialisierungsmethode myUtils_Initialize nicht zusammenpassen, auch wenn ich jetzt nicht genau sagen kann wo eigentlich neu geladen wird...

Johannes

[raspklaus]

Die Meldungen bestehen weiterhin, auch bei einem Umbenennen.

Auf einem Testsystem habe ich nun eine leere Utils angelegt und ein e Sub eingefügt. Nach dem zweiten Abspeichern kommen die Meldungen wieder

[viegener]

Kannst Du die Logeinträge nach dem Umbenennen mal posten?
Was hast Du denn umbenannt: Die Datei oder die Initialize Funktion?

Auf was für einer Plattform läuft Dein System?
Johannes

[betateilchen]

Einfache Regel: Nicht alles, was im Log steht, sind Fehler.

Die redefined-Meldungen sind bei einem reload eines Moduls doch völlig normal. Schlimm wäre, wenn sie NICHT kämen.

Das sind auch in keinster Weise Fehlermeldungen, sondern schlichtweg Hinweise über erfolgte Aktionen.

Worüber diskutiert Ihr hier eigentlich?

[marvin78]

Das schrieb ich oben schon. Bei ihm kommen sie beim Start. Ich nehme an, es ist der Name.

[betateilchen]

Auf einem Testsystem habe ich nun eine leere Utils angelegt und ein e Sub eingefügt. Nach dem zweiten Abspeichern kommen die Meldungen wieder

Eine 99_myUtils.pm Datei wird nach einer Veränderung im integrierten Frontend-Editor von fhem nach dem Abspeichern automatisch neu geladen!

[betateilchen]

Bei ihm kommen sie beim Start. Ich nehme an, es ist der Name.

Bitte mal ein "ls -al 99_*" im Verzeichnis FHEM ausführen und hier posten.

[viegener]

Bitte mal ein "ls -al 99.*" im Verzeichnis FHEM ausführen und hier posten.

Zumindest unter UNIX würde ich

Code Auswählen Erweitern

ls -al 99* vorschlagen

Johannes