Medienwiedergabe hängt sporadisch. Demigrator? Logs anbei

[Jerome]

Erstmal Beschreibung der Ausgangslage und des Symptoms
- WHS mit Videofiles
- Searchindexer ist aus
- VSS ist ebenfalls ausgeschaltet (mit WHS Toolkit)
- Wiedergabe von Videos über einen HTPC mit Windows XP und XBMC per SMB vom WHS Ordner
- in sporadischen Abständen hängt die Wiedergabe der Videos, nach ein paar Sekunden fängt er wieder an zwischenzuspeichern und spielt weiter
- es liegt nicht am Videofile selber

Kabel/Router/lokale Probleme am Client etc hab ich aus meiner Sicht durch Tests/Neuinstallationen ausgeschlossen.
Unnötige Dienste wie den Seachindexed und VSS habe ich mittels Infos hier aus dem Forum deaktiviert.
Ich habe mir die Zeitpunkte der Probleme notiert und exakt zu diesem Zeitpunkte auch die passenden Einträge in den Logs gefunden.

Von daher erhoffe ich mir das mir vielleicht jemand helfen kann das Log richtig zu interpretieren.
In den Logs ist zur Zeit des Problems auch immer genau das Videofile zu sehen das ich zu der Zeit angesehen habe, der Hänger war auch zur selben Sekunde wie der Eintrag "Nonfatal exception in Secondary Pass" im Log. Die betroffenen Shares sind nicht dupliziert, ich habe einige Shares zur Duplizierung aktiv, aber nicht den Folder "Videos"

Ich vermute der versucht da irgendetwas zu optimieren und blockiert/verlangsamt den Zugriff auf die Files für eine gewisse Dauer.
Wie kann ich das verhindern?

Erstes Problem um 6:28h

Code: Alles auswählen

Server\logs\DEUtil.050310.043002.2472.log
[10.05.2010 06:26:12  c6c] Sleeping between passes 3591841,3815ms
[10.05.2010 06:26:12  c6c] MigrationDisabled = 0
[10.05.2010 06:26:12  c6c] Audit Grace Period is set to: 1440
[10.05.2010 06:26:12  c6c] ***Starting Primary Pass
[10.05.2010 06:27:44  c6c] Primary Pass: (duplication) 91748,9348ms
[10.05.2010 06:27:44  c6c] ***Starting Secondary Pass
[10.05.2010 06:27:44  c6c] Volume information - 
Volume - Id = fe39b4ec-39cf-4967-9b5a-7259385daf52 Size = 1377 GB Free = 1098220 MB
Volume - Id = b2530063-6a06-45f8-9286-fcc3fee8a80b Size = 1863 GB Free = 857237 MB
Volume - Id = 8be5ab62-9a5b-44c6-8903-0d4393b1f26f Size = 1397 GB Free = 20119 MB
Volume - Id = 76ef6c8f-0768-40c7-b2c0-81b55897eac8 Size = 1397 GB Free = 18518 MB
Volume - Id = 57486f64-297c-445b-a22d-d045141af4de Size = 1863 GB Free = 1140003 MB
Volume - Id = 192f851b-c2b9-4d2d-ab64-2ef8618986e0 Size = 1863 GB Free = 585688 MB
[10.05.2010 06:28:00  c6c] OpenedFile::Lock: Error 300 from SendToFilter(BatchOplock) on c:\fs\H\DE\shares\Videos\Shows\24\Season 08\24-s08e11.mkv
[10.05.2010 06:28:00  c6c] nonfatal - DEFileFromShadow(c:\fs\H\DE\shares\Videos\Shows\24\Season 08\24-s08e11.mkv,fe39b4ec-39cf-4967-9b5a-7259385daf52) threw - err=170
[10.05.2010 06:28:00  c6c] Nonfatal exception in Secondary Pass on c:\fs\H\DE\shares\Videos\Shows\24\Season 08\24-s08e11.mkv: error =170
[10.05.2010 06:28:36  c6c] Secondary Pass: (balancing) 51936,4695ms
[10.05.2010 06:28:36  c6c] Full Primary and Secondary Pass 143686,2919ms

Zweites Problem um 8:33h

Code: Alles auswählen

[10.05.2010 08:00:00]
TraceCleanup: discarding log C:\Dokumente und Einstellungen\All Users\Anwendungsdaten\Microsoft\Windows Home Server\logs\DEUtil.050310.060000.2216.log
TraceCleanup: discarding log C:\Dokumente und Einstellungen\All Users\Anwendungsdaten\Microsoft\Windows Home Server\logs\DEUtil.050310.060000.2472.log
TraceCleanup: discarding log C:\Dokumente und Einstellungen\All Users\Anwendungsdaten\Microsoft\Windows Home Server\logs\DEUtil.050310.070000.2472.log
[10.05.2010 08:31:15  c6c] Sleeping between passes 3591837,1374ms
[10.05.2010 08:31:15  c6c] MigrationDisabled = 0
[10.05.2010 08:31:15  c6c] Audit Grace Period is set to: 1440
[10.05.2010 08:31:15  c6c] ***Starting Primary Pass
[10.05.2010 08:33:16  c6c] Primary Pass: (duplication) 120178,255ms
[10.05.2010 08:33:16  c6c] ***Starting Secondary Pass
[10.05.2010 08:33:16  c6c] Volume information - 
Volume - Id = fe39b4ec-39cf-4967-9b5a-7259385daf52 Size = 1377 GB Free = 1098220 MB
Volume - Id = b2530063-6a06-45f8-9286-fcc3fee8a80b Size = 1863 GB Free = 857237 MB
Volume - Id = 8be5ab62-9a5b-44c6-8903-0d4393b1f26f Size = 1397 GB Free = 20119 MB
Volume - Id = 76ef6c8f-0768-40c7-b2c0-81b55897eac8 Size = 1397 GB Free = 18518 MB
Volume - Id = 57486f64-297c-445b-a22d-d045141af4de Size = 1863 GB Free = 1140003 MB
Volume - Id = 192f851b-c2b9-4d2d-ab64-2ef8618986e0 Size = 1863 GB Free = 585688 MB
[10.05.2010 08:33:36  c6c] OpenedFile::Lock: Error 300 from SendToFilter(BatchOplock) on c:\fs\F\DE\shares\Videos\Shows\24\Season 08\24-s08e13.mkv
[10.05.2010 08:33:36  c6c] nonfatal - DEFileFromShadow(c:\fs\F\DE\shares\Videos\Shows\24\Season 08\24-s08e13.mkv,fe39b4ec-39cf-4967-9b5a-7259385daf52) threw - err=170
[10.05.2010 08:33:36  c6c] Nonfatal exception in Secondary Pass on c:\fs\F\DE\shares\Videos\Shows\24\Season 08\24-s08e13.mkv: error =170
[10.05.2010 08:34:02  c6c] Secondary Pass: (balancing) 46026,2192ms
[10.05.2010 08:34:02  c6c] Full Primary and Secondary Pass 166205,3439ms

Die Probleme tauchen also immer in der Phase "Secondary Pass: (balancing) " auf. Was treibt der denn da eigentlich?

[steve0564]

Und der WHS läuft auf welcher Hardware??

[Jerome]

Athlon Dual Core 4450e
4 GB DDR2 Ram
3 * 1,5 TB WD Caviar Green EADS
3 * 2,0 TB WD Caviar Green EADS

VG
Jerome

[Nobby1805]

Welches PP läuft auf deinem WHS ?

Nach meiner Vorstellung gleich der DEmigrator beim Balancing die Füllung der Platten aus ... aber ich hab mal mit einem Logger gesehen dass er dabei alle Dateien anfasst (und was auch immer damit macht)

[Jerome]

Habe PP3 am laufen.

Plattenausgleich? Also die Auslastung gleichmässig über die Platten verteilen? Ich dachte das der WHS das prinzipiell nicht macht. Naja, wegen der Duplizierung verteilt er klar was auf andere Platten, aber zur Auslastungsverteilung? Falls er das wirklich vorhaben sollte, so ist er dramatisch gescheitert bei mir Einige Platten sind bei 98%, andere bei 30%.

Würd mich trotzdem interessieren was der WHS da treibt, kann quasi keinen Film ohne Aussetzer anschauen. Die Aussetzer kommen gerne kurz nach vollen oder halben Stunden von der Uhrzeit her. Scheint also ne regelmässige Tätigkeit zu sein. Demigrator abschalten ist auf Dauer eigentlich keine Lösung.
Bin kurz davor die drei 2TB Platten aus dem Pool des WHS rauszunehmen und einzeln laufen zu lassen mit eigenständiger Freigabe, da dürften sie dann eigentlich ruhe haben vorm Demigrator. Aber damit hebel ich ja eigentilch den Sinn des WHS etwas aus.

[sTunTe]

Hallo.

Plattenausgleich? Also die Auslastung gleichmässig über die Platten verteilen?

Nein und das ist auch gut so.
Aber der demigrator schaut nach, ob Dateien verschoben werden müssen.

Btw: Hier hatte ich mal versucht zu erklären, warum der WHS die Platten nacheinander befüllt: viewtopic.php?f=9&t=2993

In Deinem Fall könnte das gleiche Problem herrschen, wie bei meinem WHS, bzw. dem verwendeten Mainboard.
Bei deaktivertem AHCI-Modus können die Schreib-/Leseraten der Platten stark einbrechen, wenn auf mehrere Platten gleichzeitig zugegriffen wird.
In Deinem Fall: Video streamen, Demigrator.
Da Du den AHCI-Modus nachträglich nicht so ohne Weiteres aktivieren kannst, wirst Du um eine Neuinstallation nur schwierig herumkommen.
Ist momentan aber nur eine Vermutung von mir.

Gruß
sTunTe

[Nobby1805]

Würd mich trotzdem interessieren was der WHS da treibt,

mich auch ... aber ich kenne keine Aussage von MS dazu

kann quasi keinen Film ohne Aussetzer anschauen. Die Aussetzer kommen gerne kurz nach vollen oder halben Stunden von der Uhrzeit her.

der DEmigrator ist aber an keien feste Zeit gebunden, wenn er fertig ist legt er sich für 3600 Sekunden schlafen und fängt dann wieder an

Scheint also ne regelmässige Tätigkeit zu sein. Demigrator abschalten ist auf Dauer eigentlich keine Lösung.

Versuch doch mal mit dem Leistungsmonitor die CPU, Platten, LAN ... Auslastung zu monitoren ... im Sekundenrhytmus in einen File legen und im Nachhinein mit Excel analysieren ... falls dann das Streaming überhaupt noch klappt

[Jerome]

Den Hinweis mit dem AHCI und Problemen bei Zugriff auf mehrere Platten gleichzeitig hab ich nicht so richtig kapiert.
Das Problem tritt ja nicht auf beim verteilten Zugriff, sondern immer exakt dann wenn der Demigrator genau die eine Datei anfasst die ich gerade anschaue.
So wie ich das Log mal laienhaft interpretiere ist der Demigrator ne ganze Weile aktiv am schauen, irgendwann kommt er dann auf die Datei die ich aktuell verwende und dann passieren zwei Ereignisse:
A) Wiedergabe am Client hängt
B) Log Einträge zu dieser Datei (siehe oben) erscheinen im WHS
Also nahm ich an das ich eigentlich kein generelles Performance Problem hab, sondern nur dem auf die Schliche kommen muss was der WHS von der Datei will die ich in Verwendung habe und wie ich das umgehen kann.
Oder meint ihr ehr das die gleichzeitige Verwendung dieser Datei kein Problem ist, die Fehlermeldungen wären normal und kommen bei jedem vor, ich müsste nur die Allgemeinperformance so weit optimieren das der Client trotz des Fehlers und des Zugriffes durch den WHS keine Symptome mehr zeigt?

Hat jemand Infos wo diese Fehlermeldungen laut Log erläutert sind?

Bin nicht mehr sicher ob ich auf dem richtigen Weg mit meiner Fehlersuche bin, bisher wollt ich eigentlich die Fehlerursache für die EInträge laut Log finden und das abstellen.
Wenn es nicht abstellbar ist und der Demigrator halt eben immer die Wiedergabe stört, dann müsste ich die Platten auf denen die Videofiles sind rausnehmen aus dem Pool.

Vielen Dank übrigens für eure Hilfe!

[Nobby1805]

So wie ich das Log mal laienhaft interpretiere ist der Demigrator ne ganze Weile aktiv am schauen, irgendwann kommt er dann auf die Datei die ich aktuell verwende und dann passieren zwei Ereignisse:
A) Wiedergabe am Client hängt
B) Log Einträge zu dieser Datei (siehe oben) erscheinen im WHS
Also nahm ich an das ich eigentlich kein generelles Performance Problem hab, sondern nur dem auf die Schliche kommen muss was der WHS von der Datei will die ich in Verwendung habe und wie ich das umgehen kann.

Ich kann mir das eigentlich nur so erklären, dass der Wiedergabestream die Datei nicht für Zugriffe sperrt und dann der DEmigrator zu dieser Datei kommt und sie sperrt und ein Problem feststellt, während das Problem gemeldet wird bleibt die Datei gesperrt (evt. macht er auch mehrere Retries) und dann will der Stream wieder zugreifen und hakt dann e

Oder meint ihr ehr das die gleichzeitige Verwendung dieser Datei kein Problem ist, die Fehlermeldungen wären normal und kommen bei jedem vor, ich müsste nur die Allgemeinperformance so weit optimieren das der Client trotz des Fehlers und des Zugriffes durch den WHS keine Symptome mehr zeigt?

wenn es so ist wie ich vermute, dann liegt da ein Konzepfehler vor und ich bezweifle dass man da etwas optimieren kann.Selbst wenn man den Zyklus des DEmigrator verlängert sinkt nur die Wahrscheinlichkeit

Hat jemand Infos wo diese Fehlermeldungen laut Log erläutert sind?

irgendwo in MS internen Dokumenten

Bin nicht mehr sicher ob ich auf dem richtigen Weg mit meiner Fehlersuche bin, bisher wollt ich eigentlich die Fehlerursache für die EInträge laut Log finden und das abstellen.

Ich würde es nicht Fehler- sondern eher Infomeldung nennen

[Jerome]

ok. Ich hatte so was schon fast befürchtet.

Das behakt sich gegenseitig. Das Videofile an sich hat keinen Fehler, im WHS log wird auch immer nur das eine File als Fehler gelistet das ich gerade aktiv anschaue (ich streame übrigens nicht, der Client gibt die Datei einfach vom gemappten Laufwerk wieder). Also wird wohl die Tatsache das ich es anschaue zur WHS Meldung führen, und die Versuche des WHS auf das File draufzukommen führen zum haken der Wiedergabe. Deadlock.

Da wird mir wohl nichts anderes übrigbleiben als meine Videofiles mal komplett vom Plattenpool runterzunehmen und die grossen 2 TB Platten alle einzeln manuell auf dem WHS freigeben. Also am Pool vorbei. Ist zwar eigentlich nicht im Sinne des Erfinders, aber was soll ich machen. Mist das. Der neue WHS Vail scheint das Problem mit dem Demigrator ja nicht mehr in dieser Form zu haben weil er keine Files mehr direkt angeht. Aber als Ersatz für meinen laufenden WHS ist die Beta wohl nicht geeignet.

Das Problem tritt wohl auch nur bei grossen Files auf. Bei Musiktiteln hatte ich noch nie ein Problem, nur bei grossen Videofiles

Ich werde also die Laufwerke einzeln rausnehmen und auf einen stabileren WHS Vail warten

Danke nochmals

[sTunTe]

im WHS log wird auch immer nur das eine File als Fehler gelistet

Dieser "Fehler" ist kein Feher, sondern lediglich die Info des Demigrators, das er momentan nicht auf diese Datei zugreifen kann, da in Gebrauch.

Da wird mir wohl nichts anderes übrigbleiben als meine Videofiles mal komplett vom Plattenpool runterzunehmen ....

Damit beseitigst Du aber nicht den Fehler.

Das Problem tritt wohl auch nur bei grossen Files auf.

Das Problem triit normlerweise garnicht auf.
Ansonsten wäre das Forum bis an die Decke gefüllt mit Meldungen alà "Hilfe, meine Videos ruckeln" o.ä.

Ich an Deiner Stelle würde erstmal versuchen den Fehler zu finden...
Erstell Dir eine neue Freigabe, Duplizierung aus, ein Videofile rein.
Nachschauen auf welcher Platte das File liegt (C:\fs\xx)
Diese Platte mit dem Leistungsmonitor (perfmon.exe) des WHS überwachen.
Unter "logischer Datenträger" die "Aktuelle Warteschlagenlänge", "Leerlaufzeit (%)", "Lesezeit (%)" und "Schreibzeit (%)" für die entsprechende Platte hinzufügen.

Außerdem würde ich noch den Prozessor und die Netzwerkkarte mit einbeziehen...
Nicht das wir hier am Ende an der völlig falschen Stelle suchen.
Für den "Prozessor" sollte die "Leerlaufzeit (%)" genügen.
Bei der "Netzwerkschnittstelle" die "Bytes gesendet/s", "Bytes empfangen/s" und die "Ausgabewarteschlangenlänge".

Anschließend lässt Du das Video auf Deinem Clienten laufen und bei einem Aussetzer machst Du einen Screenshot des Leistungsmonitors.
Mal sehen wo es da genau hakt...

Gruß
sTunTe

[Nobby1805]

im WHS log wird auch immer nur das eine File als Fehler gelistet

Dieser "Fehler" ist kein Feher, sondern lediglich die Info des Demigrators, das er momentan nicht auf diese Datei zugreifen kann, da in Gebrauch.

Hallo Michael

WO habe ich das geschrieben ?

Gruß Norbert

[sTunTe]

nanu?
Da ist irgendwas beim Zitieren falsch gelaufen...
Da hätte eigentlich "Jerome" stehen sollen...
Ich ändere das mal...

Gruß
sTunTe