Ruhezustand Problem mit 1.5

[mrkaehler]

Hallo Martin,

die Maschine die ich in diesem Beitrag (viewtopic.php?f=62&t=12138) mit Vail im Test hatte läuft jetzt mit einem WHSv1. Einige Zeit (3-4 Wochen) lief alles problemlos.
Jetzt ist die LO-Beta1.5 drauf - damit ging es auch noch alles.
Dann kam ein Windows-Update (Silverlight) und die Installation von Chrome - jetzt geht er nicht mehr in den Ruhezustand.
Per "Hand" kann ich ihn in den Ruhezustand schicken, dann schläft er durch bis zum Wecken. Die Server logs sind per eMail unterwegs ...

Gruß Robert

[mrkaehler]

Also ich hab's jetzt mehrfach durchexerziert: Ruhezustand manuell ausgelöst funktioniert zufriedenstellend.
Der von LO1.5b fabrizierte läuft ungefähr so ab:

Code: Alles auswählen

2011-02-28 00:52:59:799 [  14] DEBUG ++ Global wait timer expired, running delayed action
2011-02-28 00:52:59:799 [  14] DEBUG RunAction: wait for lock
2011-02-28 00:52:59:799 [  14] DEBUG RunAction: got lock
2011-02-28 00:52:59:861 [  14] DEBUG Reading known services from C:\Programme\Windows Home Server\LightsOut.KnownServices.txt
2011-02-28 00:52:59:877 [  14] DEBUG Read 9 known services
2011-02-28 00:52:59:893 [  14] DEBUG Service RemoteAccess, has start mode Disabled
2011-02-28 00:52:59:893 [  14] DEBUG Found service Routing und RAS [RemoteAccess], state Stopped, mode Disabled
2011-02-28 00:52:59:908 [  14] DEBUG Service Spooler, has start mode Automatic
2011-02-28 00:52:59:908 [  14] DEBUG Found service Druckwarteschlange [Spooler], state Running, mode Automatic
2011-02-28 00:52:59:908 [  14] DEBUG >>>> Hibernate force False
2011-02-28 00:52:59:924 [  14] DEBUG WHSClientMonitor: suspended
2011-02-28 00:52:59:924 [  14] DEBUG BackupMonitor: suspended
2011-02-28 00:52:59:924 [  14] DEBUG RemoteAccessMonitor: suspended
2011-02-28 00:52:59:924 [  14] DEBUG IPDeviceMonitor: suspended
2011-02-28 00:52:59:939 [  14] DEBUG NetworkMonitor: suspended
2011-02-28 00:52:59:955 [  14] DEBUG CPUMonitor: suspended
2011-02-28 00:52:59:955 [  14] DEBUG ServerRuntime: suspended
2011-02-28 00:52:59:971 [  14] DEBUG   HandleServices: Spooler Status=Running
2011-02-28 00:52:59:971 [  14] DEBUG     stopping Spooler
2011-02-28 00:53:02:236 [  14] DEBUG     service Spooler Status Stopped
2011-02-28 00:53:02:236 [  14] DEBUG   HandleServices: DriveExtenderMigrator Status=Running
2011-02-28 00:53:02:236 [  14] DEBUG     stopping DriveExtenderMigrator
2011-02-28 00:53:04:377 [  14] DEBUG     service DriveExtenderMigrator Status Stopped
2011-02-28 00:53:04:377 [  14] DEBUG last event recorded: InitiatedHibernation
2011-02-28 00:53:04:455 [  13] DEBUG --- Power event QuerySuspend ---
2011-02-28 00:53:04:471 [  13] DEBUG --- Power event Suspend ---
2011-02-28 00:53:04:471 [  13] DEBUG RemoteAccessMonitor: suspended
2011-02-28 00:53:04:471 [  13] DEBUG CPUMonitor: suspended
2011-02-28 00:53:04:471 [  13] DEBUG ServerRuntime: suspended
2011-02-28 00:53:04:486 [  13] DEBUG last event recorded: Suspend
2011-02-28 00:53:04:486 [  13] DEBUG -------------------------


2011-02-28 00:53:07:861 [   7] DEBUG Das System wurde in den Ruhezustand versetzt.
2011-02-28 00:54:03:359 [  14] DEBUG Action Hibernate successfull
2011-02-28 00:54:03:484 [  13] DEBUG --- Power event ResumeAutomatic ---
2011-02-28 00:54:03:531 [  13] DEBUG last event recorded: Resume
2011-02-28 00:54:03:625 [  13] DEBUG   HandleServices: DriveExtenderMigrator Status=Stopped
2011-02-28 00:54:03:656 [  13] DEBUG Service DriveExtenderMigrator, has start mode Manual
2011-02-28 00:54:03:687 [  13] DEBUG     starting DriveExtenderMigrator
2011-02-28 00:54:19:562 [  13] DEBUG     service DriveExtenderMigrator Status Running
2011-02-28 00:54:19:578 [  13] DEBUG   HandleServices: Spooler Status=Stopped
2011-02-28 00:54:19:578 [  13] DEBUG Service Spooler, has start mode Automatic
2011-02-28 00:54:19:593 [  13] DEBUG     starting Spooler
2011-02-28 00:54:20:343 [  13] DEBUG     service Spooler Status Running
2011-02-28 00:54:20:343 [  13] DEBUG   HandleServices: DriveExtenderMigrator Status=Running
2011-02-28 00:54:20:406 [  13] DEBUG Run: 
2011-02-28 00:54:20:437 [  13] DEBUG ServerRuntime: resumed
2011-02-28 00:54:20:484 [  13] DEBUG CalendarMonitor: Resume, action cleared, last active=False, action=DoNothing, force=False
2011-02-28 00:54:20:484 [  13] DEBUG WHSClientMonitor: resumed
2011-02-28 00:54:20:484 [  13] DEBUG BackupMonitor: resumed
2011-02-28 00:54:20:515 [  13] DEBUG RemoteAccessMonitor: resumed
2011-02-28 00:54:20:515 [  13] DEBUG IPDeviceMonitor: resumed
2011-02-28 00:54:20:515 [  13] DEBUG NetworkMonitor: resumed
2011-02-28 00:54:20:546 [  13] DEBUG CPUMonitor: resumed
2011-02-28 00:54:20:546 [  13] DEBUG Licensee SingleUser 29
2011-02-28 00:54:30:484 [   4] DEBUG - CalendarMonitor: Calendar entry is not active
2011-02-28 00:54:30:515 [   4] DEBUG >> Global wait timer enabled, Action Hibernate, Interval 20 minutes
2011-02-28 01:01:10:515 [   8] DEBUG Scan network: Check every 00:30:00 triggered

Wenn der Meister nichts mehr dazu sagen kann, würde ich auf die vorhergehende Stable-Version (1.0.4.1212) zurücksetzen.
Was sagen eigentlich die Clients dazu? Erfolgt hier der Downgrade auch automatisch (analog zum Upgrade)?

[Martin]

Hm, mir ist da der Zusammenhang mit dem Update unklar. Ich gehe auch mal davon aus dass du den Server schon mal neu gestartet hast und auch den Eventlog überprüft hast?

Der Teil, der den Ruhezustand auslöst hat sich zwischen 1.0.4 und 1.5 nicht geändert.
Dein Server fährt in den Ruhezustand und wacht sofort wieder auf. Kannst du mir mal den Ablauf mit einem manuellen Ruhezustand zukommen lassen bzw. die Zeit angeben wo du das getestet hattest.

Gruß
Martin

[mrkaehler]

Am 24.02. um 07:22 z.B.

Code: Alles auswählen

2011-02-24 07:18:08:812 [   3] DEBUG + WtsMonitor: Active, console session exists
2011-02-24 07:18:08:812 [   3] DEBUG ACTIVITY SIGNALED BY: ConsoleSession, action=Hibernate
2011-02-24 07:18:26:968 [   4] DEBUG PipeServer: Read 0 bytes, already disposed=False
2011-02-24 07:18:44:828 [   6] DEBUG >> Sent UpdateLicense
2011-02-24 07:18:44:843 [   6] DEBUG PipeServer: Client has connected
2011-02-24 07:20:48:796 [  13] DEBUG TaskList modified old=19:28, new=07:20
2011-02-24 07:20:48:796 [  13] DEBUG Exception in CreateListFromFile C:\Dokumente und Einstellungen\All Users\Anwendungsdaten\LightsOut\TaskList.xml: Fehler im XML-Dokument (2,2).
2011-02-24 07:20:48:796 [  13] DEBUG ++ SyncList started
2011-02-24 07:20:48:796 [  13] DEBUG ++ SyncList finished
2011-02-24 07:21:52:078 [   3] DEBUG PipeServer: Read 0 bytes, already disposed=False
2011-02-24 07:22:03:593 [  13] DEBUG --- Power event QuerySuspend ---
2011-02-24 07:22:03:609 [  13] DEBUG --- Power event Suspend ---
2011-02-24 07:22:03:609 [  13] DEBUG WHSClientMonitor: suspended
2011-02-24 07:22:03:609 [  13] DEBUG BackupMonitor: suspended
2011-02-24 07:22:03:609 [  13] DEBUG RemoteAccessMonitor: suspended
2011-02-24 07:22:03:625 [  13] DEBUG IPDeviceMonitor: suspended
2011-02-24 07:22:03:625 [  13] DEBUG NetworkMonitor: suspended
2011-02-24 07:22:03:625 [  13] DEBUG CPUMonitor: suspended
2011-02-24 07:22:03:625 [  13] DEBUG ServerRuntime: suspended
2011-02-24 07:22:03:625 [  13] DEBUG last event recorded: Suspend
2011-02-24 07:22:03:640 [  13] DEBUG -------------------------


2011-02-24 07:22:04:531 [   4] DEBUG Das System wurde in den Ruhezustand versetzt.
2011-02-24 15:51:21:562 [  22] DEBUG --- Power event ResumeAutomatic ---
2011-02-24 15:51:21:718 [  22] DEBUG last event recorded: Resume
2011-02-24 15:51:21:718 [  22] DEBUG   HandleServices: DriveExtenderMigrator Status=Running
2011-02-24 15:51:21:765 [  24] DEBUG --- Power event ResumeSuspend ---
2011-02-24 15:51:21:796 [  22] DEBUG   HandleServices: Spooler Status=Running
2011-02-24 15:51:21:796 [  22] DEBUG   HandleServices: DriveExtenderMigrator Status=Running
2011-02-24 15:51:21:796 [  22] DEBUG Run: 
2011-02-24 15:51:21:875 [  22] DEBUG ServerRuntime: resumed
2011-02-24 15:51:21:921 [  22] DEBUG CalendarMonitor: Resume, action cleared, last active=False, action=DoNothing, force=False
2011-02-24 15:51:21:921 [  22] DEBUG WHSClientMonitor: resumed
2011-02-24 15:51:22:125 [  22] DEBUG BackupMonitor: resumed
2011-02-24 15:51:22:125 [  22] DEBUG RemoteAccessMonitor: resumed
2011-02-24 15:51:22:125 [  22] DEBUG IPDeviceMonitor: resumed
2011-02-24 15:51:22:125 [  22] DEBUG NetworkMonitor: resumed
2011-02-24 15:51:22:156 [  22] DEBUG CPUMonitor: resumed
...

Im Eventlog sind keine Auffälligkeiten. Der einzige, der ab und zu 'ne Warnung auswirft ist der WinHttpAutoproxySvc:
"The WinHTTP Web Proxy Auto-Discovery Service is shutting down and not accepting client requests." - Scheint nicht dramatisch zu sein...
Ich hatte bei meiner ersten Installation alle möglichen Dienste, die mir nicht notwendig erschienen abgeschaltet und mich dann gewundert, was ab und zu für Probleme hochkamen, daher bin ich jetzt etwas vorsichtiger und lasse solche vermeintlich nicht benötigten Dienste erstmal an ...

Gruß Robert

[Martin]

Hi Robert, ich mach die mal eine Testversion und melde mich dann wieder.,

Gruß
Martin

[mrkaehler]

Als ich eben den WHS direkt aus dem Anmeldebildschirm in den Ruhezustand fahren wollte, kam:
"Bitte warten Sie bis der Volumenschattenkopie-Dienst das Volume C: für den Ruhezustand vorbereitet." ... "OK"
...
"Das System ist jetzt bereit für den Ruhezustand." ... "OK" (oder sinngemäß)

Kann das eine Ursache sein? (Ich habe diesen Dienst bestimmt nicht bewusst aktiviert ...)

Gruß Robert

Edit: Wenn ich mir die Eingenschaften von C: anschaue ist aber bei den Schattenkopien alles deaktiviert - merkwürdig.

[Martin]

War da vielleicht gerade ein Backup aktiv? Das braucht den Dienst auch...

Gruß
Martin

[mrkaehler]

Nö - kein Backup. War kein Client mehr da ... Ist auch nicht wieder aufgetreten, ich mache die Kiste jetzt jede Nacht so aus.

[mrkaehler]

Hi Robert, ich mach die mal eine Testversion und melde mich dann wieder.,

Gruß
Martin

[Martin]

Hat sich leider etwas verzögert (MVP Summit und Urlaub), kommt nächste Woche.

Gruß
Martin

[mrkaehler]

... und die Installation von Chrome - jetzt geht er nicht mehr in den Ruhezustand.
Per "Hand" kann ich ihn in den Ruhezustand schicken, dann schläft er durch bis zum Wecken. ...

Ich glaube, ich bin der Sache auf der Spur. Der Chrome-Installer hatte im Taskplaner diverse Tasks angelegt.
Ich habe die gerade entdeckt und alle gelöscht.
Ein "Probe-Ruhezustand" aus der LO-Konsole hat daraufhin schon mal funktioniert.
Wenn der WHS heute abend ordnungsgemäß einschläft war das die Ursache - wenngleich ich nicht genau sagen kann warum ...

[Martin]

Danke für die Info, welche Task werden denn da ausgeführt? Muss ich nächste Woche mal im Büro testen.

Danke
Martin

[mrkaehler]

Scheint bei jeder Chrome-Installation angelegt zu werden. Ich habe diese Einträge auch auf dem Win7-Laptop:
GoogleUpdateTaskUser-GUID-Core, jeden Tag um xx:yy
GoogleUpdateTaskUser-GUID-UA, jeden Tag um xx:yy, Wiederholen alle Stunde für die Dauer eines Tages (Zeitplan)

Edit: Das war es leider nicht er spielt immer noch das runter-gleich-wieder-hoch-Spiel.

[Martin]

Hm, das war dieses ION Board, oder?
Das sofortige Aufwachen passiert auch beim manuellen Standby?

Martin

[mrkaehler]

Hm, das war dieses ION Board, oder?
Das sofortige Aufwachen passiert auch beim manuellen Standby?

Martin

Ja - ein PointOfView.
Das irritiert mich ja so: Der Ruhezustand aus dem Anmeldebildschirm (reale Konsole) funktioniert wunderbar.
Bei den Test über die WHS-Konsole oder RDP etc. bin ich mir immer nicht so sicher, da ich diese Sachen in der Überwachung habe und ja dann auch immer mindestens ein Client an ist.
Zum zweiten lief der Ruhezustand auch schon mal ein paar Wochen - bis zu dem Tag mit dem Silverlight/Chrome-Update - sonst ist das System eigentlich unverändert. "eigentlich" weil ich ein paar Problemchen mit den 1,5TB-Samsung-HDs hatte und schon dreimal tauschen musste (zum Glück alle in der Garantie sofort ersetzt bekommen). Deshalb ist auf dem System im Moment auch noch relativ viel freier Platz.

Gruß Robert

Edit: letzte Nacht ist der WHS ordnungsgemäß eingeschlafen Unterschied zum Tag vorher
Ich habe nur dafür gesorgt, dass kein Client im StandBy ist - alle waren jetzt "wirklich" aus. Aber nach meinem Kenntnisstand könnte ein Client, der nicht aus ist, nur das Abschalten verhindern - nicht einen sofortigen Neustart veranlassen (es ging ja innerhalb von 10tel-Sekunden weiter)
Ich bleib dran - aber es ist besser geworden, nach dem Löschen der Tasks.

Edit2: So - nun ist einige Zeit vergangen und der WHS läuft wieder so, wie ich es geplant habe.
Als Fazit kann ich nur festhalten, dass man bitte schön bei merkwürdigem Shutdown-Verhalten mal in die geplanten Tasks schauen möchte.
Bestimmte Kombinationen/Zeitpläne können offensichtlich gehöriges Unheil anrichten.