IPS 4.0 - Dienst beendet sich "vonselbst"

IP-Symcon
141

Die Frage wäre, ob IP-Symcon zu viel Speicher verbraucht, oder ob deine psftp.exe so viel RAM „blockieren“, dass IP-Symcon irgendwann keinen RAM mehr kann.

paresy

142

Naja, das System hat 32GB, ips.exe nutzt 36 MB… Daran liegt es nicht. Es gab jetzt wieder einen Crash samt Log:

18:04:22 | 00000 | ERROR   | TimerPool            | resource unavailable try again: resource unavailable try again
18:05:07 | 24049 | ERROR   | TimerPool            | Archive Handler (CommitData): bad allocation
18:05:07 | 00000 | ERROR   | DataServer           | bad allocation
18:15:34 | 00000 | CUSTOM  | PHP                  | Error: Warning: Zeitüberschreitung beim Warten auf Antwort
   Error in Script - on Line 1
  133 in IPSLibrary\app\core\IPSLogger\IPSLogger.inc.php (call IPSLogger_Out)
   37 in IPSLibrary\app\core\IPSLogger\IPSLogger_PhpErrorHandler.inc.php (call IPSLogger_Err)
      in IPSLogger_PhpErrorHandler
    1 in - (call EIB_Switch)
18:15:34 | 50191 | WARNING | ScriptEngine         | Ergebnis für Ereignis 50191
<br />
<b>Warning</b>:  Zeitüberschreitung beim Warten auf Antwort in <b>-</b> on line <b>1</b><br />

Und gleich darauf, nach einem Neustart:

18:17:31 | 00000 | SUCCESS | Kernel               | *** IPS BETRIEBSBEREIT
18:24:29 | 00000 | ERROR   | TimerPool            | resource unavailable try again: resource unavailable try again
18:25:13 | 24049 | ERROR   | TimerPool            | Archive Handler (CommitData): bad allocation
18:25:13 | 00000 | ERROR   | DataServer           | bad allocation

Ist halt alles ziemlich ärgerlich…

143

32GB können auch schnell weg sein. Magst du bitte mal prüfen wie die Auslastung deines gesamten Rechners ist? Ich bin mir ziemlich sicher, dass IPS nicht das Problem hier ist :wink:

paresy

144

Naja, 55% Arbeitsspeicher, und 25% CPU ist so der Peak, also sollte ein Mangel an Arbeitsspeicher hier nicht das Problem sein. Es sei gesagt dass seit dem Update auf 4.1 diese Probleme auftreten. Ich bekomme auch massenweise Fehler beim Starten im Logfile:

18:28:12 | 24049 | MESSAGE | Archive Control      | Erstelle...
18:28:12 | 24049 | MESSAGE | Archive Control      | Generiere Zeitstempel für Sommer-/Winterzeit...
18:28:12 | 24049 | MESSAGE | Archive Control      | Lese Variablen Aggregationsdaten ... #41299
18:28:12 | 24049 | MESSAGE | Archive Control      | Update variable aggregation data... #41299
18:28:12 | 24049 | MESSAGE | Archive Control      | Lese Variablen Aggregationsdaten ... #20186
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation day for VariableID #20186. Expected: 1484521200, Found: 1484607600
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation day for VariableID #20186. Expected: 1486076400, Found: 1486162800
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #20186. Expected: 1474725600, Found: 1474722000
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #20186. Expected: 1484600400, Found: 1484596800
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #20186. Expected: 1485687600, Found: 1485684000
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #20186. Expected: 1485756000, Found: 1485752400
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #20186. Expected: 1485788400, Found: 1485784800
18:28:12 | 24049 | MESSAGE | Archive Control      | Skipped 8 more lines with continuity issues in aggregation hour for VariableID #20186
18:28:12 | 24049 | MESSAGE | Archive Control      | Update variable aggregation data... #20186
18:28:12 | 24049 | MESSAGE | Archive Control      | Lese Variablen Aggregationsdaten ... #59787
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation day for VariableID #59787. Expected: 1484521200, Found: 1484607600
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation day for VariableID #59787. Expected: 1486076400, Found: 1486162800
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #59787. Expected: 1474725600, Found: 1474722000
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #59787. Expected: 1484600400, Found: 1484596800
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #59787. Expected: 1485687600, Found: 1485684000
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #59787. Expected: 1485756000, Found: 1485752400
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #59787. Expected: 1485788400, Found: 1485784800
18:28:12 | 24049 | MESSAGE | Archive Control      | Skipped 8 more lines with continuity issues in aggregation hour for VariableID #59787
18:28:12 | 24049 | MESSAGE | Archive Control      | Update variable aggregation data... #59787
18:28:12 | 24049 | MESSAGE | Archive Control      | Lese Variablen Aggregationsdaten ... #30614
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation day for VariableID #30614. Expected: 1484521200, Found: 1484607600
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation day for VariableID #30614. Expected: 1486076400, Found: 1486162800
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #30614. Expected: 1474725600, Found: 1474722000
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #30614. Expected: 1484600400, Found: 1484596800
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #30614. Expected: 1485687600, Found: 1485684000
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #30614. Expected: 1485756000, Found: 1485752400
18:28:12 | 24049 | MESSAGE | Archive Control      | Invalid data for aggregation hour for VariableID #30614. Expected: 1485788400, Found: 1485784800
18:28:12 | 24049 | MESSAGE | Archive Control      | Skipped 8 more lines with continuity issues in aggregation hour for VariableID #30614
18:28:12 | 24049 | MESSAGE | Archive Control      | Update variable aggregation data... #30614

Von dieser Art gibt es reihenweise solcher Meldungen. Keine Ahnung ob das ein Problem sein könnte…

145

Hallo,

Na, das solche Probleme immer noch da sind :smiley: - wieviel Speicher braucht denn der IPS Prozess in diesem Fall (auf das wolltest Du wahrscheinlich heraus paresy, oder?). Was mir in diesem Zusammenhang einfällt - was wurde denn aus dem 64-bit IPS das grössere Speichernutzung zulassen würde etc.

Grüsse,
MaLu

146

um die 35MB braucht ips.exe … also nicht sonderlich viel.
Ich habe jetzt mal die Archivdaten aufgeräumt bzw einige Jahre gelöscht, mal sehen ob das was bringt

147

Bei mir ist seit gut 2 Wochen Ruhe mit den Abstürzen auf nem WIN10 Server. Ich vermute stark daran, dass es an der nervigen Windows autoupdate Funktion lag. Diese lässt sich ja nur mit Drittsoftware abschalten. Aber seit dem sie aus ist, hatte ich keine Probleme mehr.
Derzeit läuft die 4.1 Beta.

Gruß
Maze

148

ich muss mich hier leider mal dran hängen. auch bei mir schmiert der Dienst alle paar Tage ab. Gestern Abend um 21 Uhr war es dann mal wieder so weit.

Windows Log, 3 Fehler wegen PHP:

Die Beschreibung für die Ereignis-ID „4“ aus der Quelle „PHP-5.6.26“ wurde nicht gefunden. Entweder ist die Komponente, die dieses Ereignis auslöst, nicht auf dem lokalen Computer installiert, oder die Installation ist beschädigt. Sie können die Komponente auf dem lokalen Computer installieren oder reparieren.

Falls das Ereignis auf einem anderen Computer aufgetreten ist, mussten die Anzeigeinformationen mit dem Ereignis gespeichert werden.

Die folgenden Informationen wurden mit dem Ereignis gespeichert:

php[6180]
PHP Warning: PHP Startup: Unable to load dynamic library ‚C:\IP-Symcon\ext\php_pdo_firebird.dll‘ - Das angegebene Modul wurde nicht gefunden.
(C:\IP-Symcon\ips.exe)

Die Beschreibung für die Ereignis-ID „4“ aus der Quelle „PHP-5.6.26“ wurde nicht gefunden. Entweder ist die Komponente, die dieses Ereignis auslöst, nicht auf dem lokalen Computer installiert, oder die Installation ist beschädigt. Sie können die Komponente auf dem lokalen Computer installieren oder reparieren.

Falls das Ereignis auf einem anderen Computer aufgetreten ist, mussten die Anzeigeinformationen mit dem Ereignis gespeichert werden.

Die folgenden Informationen wurden mit dem Ereignis gespeichert:

php[6180]
PHP Warning: PHP Startup: Unable to load dynamic library ‚C:\IP-Symcon\ext\php_pdo_oci.dll‘ - Das angegebene Modul wurde nicht gefunden.
(C:\IP-Symcon\ips.exe)

Die Beschreibung für die Ereignis-ID „4“ aus der Quelle „PHP-5.6.26“ wurde nicht gefunden. Entweder ist die Komponente, die dieses Ereignis auslöst, nicht auf dem lokalen Computer installiert, oder die Installation ist beschädigt. Sie können die Komponente auf dem lokalen Computer installieren oder reparieren.

Falls das Ereignis auf einem anderen Computer aufgetreten ist, mussten die Anzeigeinformationen mit dem Ereignis gespeichert werden.

Die folgenden Informationen wurden mit dem Ereignis gespeichert:

php[6180]
PHP Warning: PHP Startup: Unable to load dynamic library ‚C:\IP-Symcon\ext\php_pgsql.dll‘ - Das Betriebssystem kann %1 nicht ausf�hren.
(C:\IP-Symcon\ips.exe)

im IPS Log ist der letzte Eintrag folgender:

21:19:56 | 56406 | DEBUG | ScriptEngine | Skript ausgeführt - Ereignis: 56406 ~ Absender: TimerEvent
21:19:59 | 27756 | DEBUG | ScriptEngine | Skriptausführung - Ereignis: 27756 ~ Absender: TimerEvent
21:20:00 | 32386 | DEBUG | ScriptEngine | Skriptausführung - Ereignis: 46154 ~ Absender: TimerEvent
21:20:00 | 32800 | DEBUG | ScriptEngine | Skriptausführung - Ereignis: 51692 ~ Absender: TimerEvent
21:20:00 | 56406 | DEBUG | ScriptEngine | Skriptausführung - Ereignis: 56406 ~ Absender: TimerEvent
21:20:00 | 57582 | DEBUG | ScriptEngine | Skriptausführung - Ereignis: 57582 ~ Absender: TimerEvent
21:20:00 | 32386 | DEBUG | ScriptEngine | Skript ausgeführt - Ereignis: 46154 ~ Absender: TimerEvent
21:20:00 | 32386 | ERROR | ScriptEngine | Ergebnis für Ereignis 46154
<br />
<b>Fatal error</b>: Out of memory (allocated 786432) (tried to allocate 38016 bytes) in <b>C:\IP-Symcon\scripts__compatibility.inc.php</b> on line <b>3276</b><br />

die Dumps im Minidump Ordner sind alle leer.

Das ganze läuft auf einer Windows 10 Pro Maschine mit 4 GB RAM. IPS müsste die letzte verfügbare Version aus dem Betakanal sein. Außer IPS laufen da eigentlich nichts anderes außer der Plex Server, der hat aber selten was zu tun.

Viele Grüße
Stephan

149

Ich habe dir mal eine PM für eine 64Bit Test-Version geschickt, wodurch IP-Symcon mehr Speicher zur Verfügung hat.

paresy

150

So heute Nacht hat es auch mich erwischt ( 64bit version ):

00:25:00 | 49416 | DEBUG   | ScriptEngine         | Skriptausführung - Ereignis: 57068 ~ Absender: TimerEvent
00:25:00 | 12995 | DEBUG   | ScriptEngine         | Skriptausführung - Ereignis: 59916 ~ Absender: TimerEvent
00:25:00 | 12995 | DEBUG   | ScriptEngine         | Skript ausgeführt - Ereignis: 59916 ~ Absender: TimerEvent
00:25:00 | 12995 | ERROR   | ScriptEngine         | Ergebnis für Ereignis 59916
<br />
<b>Fatal error</b>:  Out of memory (allocated 262144) (tried to allocate 12288 bytes) in <b>C:\IP-Symcon\scripts\__rpc.inc.php</b> on line <b>77</b><br />

00:25:00 | 49260 | DEBUG   | ScriptEngine         | Skript ausgeführt - Ereignis: 43640 ~ Absender: TimerEvent
00:25:00 | 49416 | DEBUG   | ScriptEngine         | Skript ausgeführt - Ereignis: 57068 ~ Absender: TimerEvent
00:25:00 | 24189 | DEBUG   | ScriptEngine         | Skript ausgeführt - Ereignis: 34295 ~ Absender: TimerEvent
00:25:00 | 24189 | ERROR   | ScriptEngine         | Ergebnis für Ereignis 34295
<br />
<b>Fatal error</b>:  Out of memory (allocated 1572864) (tried to allocate 3584 bytes) in <b>C:\IP-Symcon\scripts\IPSLibrary\app\modules\IPSPowerControl\IPSPowerControl_Manager.class.php</b> on line <b>294</b><br />

00:25:00 | 30567 | DEBUG   | ScriptEngine         | Skript ausgeführt - Ereignis: 23648 ~ Absender: TimerEvent
00:25:00 | 30567 | ERROR   | ScriptEngine         | Ergebnis für Ereignis 23648
<br />
<b>Fatal error</b>:  Out of memory (allocated 1572864) (tried to allocate 12288 bytes) in <b>C:\IP-Symcon\scripts\IPSLibrary\app\modules\IPSShadowing\IPSShadowing_Azimuth.inc.php</b> on line <b>68</b><br />

00:25:00 | 15566 | DEBUG   | ScriptEngine         | Skript ausgeführt - Ereignis: 30920 ~ Absender: TimerEvent
00:25:00 | 00000 | DEBUG   | ScriptEngine         | Skriptausführung (Text) - Länge: 281 ~ Absender: RunScript
00:25:00 | 00000 | DEBUG   | ScriptEngine         | Skript ausgeführt (Text) - Länge: 0 ~ Absender: RunScript
00:25:01 | 55797 | DEBUG   | ScriptEngine         | Skriptausführung - Ereignis: 43759 ~ Absender: TimerEvent
00:25:01 | 55797 | DEBUG   | ScriptEngine         | Skript ausgeführt - Ereignis: 43759 ~ Absender: TimerEvent
00:25:02 | 19009 | ERROR   | KernelMT             | InstanzManager: Fehler bei Instanz #55687, Meldung VM_UPDATE: Unbekannter Fehler

Das lief seit Erscheinen der 64bit Version bis heute nacht sauber …:banghead:

151

Wieviel Speicher hat denn der Dienst verbraucht? Hattest du mal geschaut, ob dieser Wert ansteigt? Hast du ein MiniDump File?

paresy

152

nee, bin gerade von der Arbeit gekommen… Server lief noch…ist Win10pro … minidump…nein . eingestellt ist das , aber er hat nix angelegt… oder ich finde die Datei nicht.

153

So ich hab nochmal geschaut… da hat sich Windows mal wieder geupdatet… eventuell hing es damit zusammen.

Hab auch nochmal auf die neuste Stable Version von IPS geupdatet… Mein IPS nimmt sich nach dem Start um 200 mb kann das jetzt sein ??

154

Hängt damit zusammen.
Seit dem ich die Updates blockiere hatte ich keinen Absturz mehr.