softhddevice -> GrabImage

e9hack · 18. April 2013

Hi,

ich verwende für mein Aurora-Plugin GrabImage vom softhddevice-Plugin. Es passiert immer mal wieder, daß der Aufruf von GrabImage 'hängen' bleibt. Der aufrufende Thread läßt sich dann auch nicht mehr beenden oder abschießen. Das Log zeigt auch nichts verdächtiges. Ich lasse alle 1 Minute Aurora einen Log-Eintrag schreiben. Wenn GrabImage hängt, stoppen die Log-Einträge:

Code

Apr 18 18:03:26 vdr vdr: [12288] (channels.c:258) changing name of channel 1426 from '392 - 16:15,;' to '392 - 18:15,;'
Apr 18 18:03:26 vdr vdr: [12288] (channels.c:258) changing name of channel 1400 from '426 - 16:30,;' to '426 - 18:30,;'
Apr 18 18:03:26 vdr vdr: [12288] (channels.c:258) changing name of channel 1533 from '393 - 16:00,;' to '393 - 18:15,;'
Apr 18 18:03:26 vdr vdr: [12288] (channels.c:258) changing name of channel 1543 from '443 - 16:00,;' to '443 - 18:15,;'
Apr 18 18:03:26 vdr vdr: [12288] (channels.c:486) linking channel 1093 from none to 1402 1426 1405 1400 1544 1533 1406 1543
Apr 18 18:03:40 vdr vdr: [12308] (outputserial.c:650) Aurora: size=533634, speed=8893 Byte/s
Apr 18 18:03:47 vdr vdr: video: slow down video, duping frame
Apr 18 18:03:47 vdr vdr: video: 10:05:10.736  +26 1406 240/\ms  33+6 v-buf
Apr 18 18:04:40 vdr vdr: [12308] (outputserial.c:650) Aurora: size=536419, speed=8939 Byte/s
Apr 18 18:04:47 vdr vdr: video: 10:06:10.736  +27 1383 240/\ms  33+6 v-buf
Apr 18 18:05:40 vdr vdr: [12308] (outputserial.c:650) Aurora: size=531809, speed=8862 Byte/s
Apr 18 18:05:47 vdr vdr: video: 10:07:10.736  +28 1360 240/\ms  33+6 v-buf
Apr 18 18:05:52 vdr vdr: [12288] (channels.c:368) changing pids of channel 1493 from 767+767=27:0;771=deu@106:0:32 to 767+767=27:0;770=deu@106,771=deu@106,772=eng@106:0:32
Apr 18 18:06:47 vdr vdr: video: 10:08:10.736  +29 1433 240/\ms  36+6 v-buf
Apr 18 18:07:13 vdr vdr: [12294] (sections.c:215) read incomplete section - len = 1005, r = 75
Apr 18 18:07:47 vdr vdr: video: 10:09:10.736  +31 1411 240/\ms  33+6 v-buf
Apr 18 18:08:47 vdr vdr: video: 10:10:10.736  +32 1340 240/\ms  33+6 v-buf
Apr 18 18:09:19 vdr vdr: video: slow down video, duping frame
Apr 18 18:09:19 vdr vdr: video: speed up video, droping frame

Alles anzeigen

Irgendwann im Zeitbereich von 18:05:40 bis 18:06:40 bleibt GrabImage hängen. Der Eintrag 'read incomplete section' kommt erst danach.

Wie kann ich das Problem einkreisen?

Gruß
e9hack

johns · 18. April 2013

Halt eine Ausgabe vor und nach dem Grabimage einbauen, dann weißt du ob Grabimage hängt.

Eigentlich ist ein Lock vorhanden, also sollte nichts hängen.

Johns

e9hack · 18. April 2013

Zitat von johns

Halt eine Ausgabe vor und nach dem Grabimage einbauen, dann weißt du ob Grabimage hängt.

Eigentlich ist ein Lock vorhanden, also sollte nichts hängen

Es passiert mal eine Woche nichts, dann hängt es 3x pro Stunde. Wenn ich direkt vor bzw. nach GrabImage was ins Log schreibe, habe ich alle 20ms 2 Zeilen. Wenn ich da nicht alle einen halben Tag das Log lösche, ist meine Platte voll.

Gruß
e9hack

johns · 18. April 2013

Dann untersuche nur den Sonderfall, wenn es passiert und nichts im Log steht, dann muß es etwas anderes sein.

Code

uint32_t start;
       uint32_t end;


       start = GetMsTicks();
       GrabImage(...);
       end = GetMsTicks();
       if ( (end - start) > 20 ) {
             Warning("grab-image hat zu lange gedauert\n");
       }

Kannst es im softhddevice direkt einbauen und beim Aufrufer auch.

Johns

e9hack · 20. April 2013

SoftHDDevice ist unschuldig. Die Aurora-Ausgabe ist mal wieder hängen geblieben, die vor und nach dem Aufruf von GrabImage erzeugten Log-Einträge laufen aber weiter. Was in dem Zusammenhang merkwürdig ist, das Live-Plugin liefert im Fernbedienungsmodus normalerweise pro Sekunde ein Bild. Aktuell gibts beim Wechseln in den Modus ein Bild, aber nur ein Standbild. Beim Verlassen und zürückwechseln gibts das nächste Standbild.

Gruß
e9hack

johns · 20. April 2013

Muß nicht umbedingt unschuldig sein. Laufen mehre Threads die grabben?
Da könnte es ein Locking Problem gehen.

Johns

e9hack · 24. April 2013

Es hat wieder zugeschlagen und es hat definitiv nichts mit softhddevice zu tun. In meinem Aurora-Plugin werden per serieller Schnittstelle, in diesem Fall ein FT232 USB UART Wandler, Daten ausgegeben:

Code

cTimeMs t;
      if (timeout < 0)
      {
        timeout = 0;
      }
      Lock.Lock();
      t.Set(0);
      cAuroraWaitThread wait_1;
      wait_1.SetMessage("write");
      wait_1.Start();
      retcode = retcode && size == write(dev_handle, buffer, size) ? true : false;
      wait_1.Stop();
      output_size += size;
      if (timeout).
      {
        cAuroraWaitThread wait_2;
        wait_2.SetMessage("sendWait");
        wait_2.Start();
        retcode = retcode && sendWait(timeout, false);
        wait_2.Stop();
      }
      if (wait)
      {
        cAuroraWaitThread wait_3;
        wait_3.SetMessage("tcdrain");
        wait_3.Start();
        tcdrain(dev_handle); <->// write buffer to device
        wait_3.Stop();
        timeout = timeout + (size * 10000 + brate / 2) / brate - t.Elapsed();
        if (timeout > 0)
        {
          cCondWait::SleepMs(timeout);
        }
      }
      Lock.Unlock();

Alles anzeigen

Ich starte vor einigen kritischen Stellen einen Thread, der nach Ablauf von 1sec einen String ins Log schreibt. Wenn alles richtig läuft, wird der Thread nach wenigen msec beendet und gibt nichts aus. Es sieht so aus, daß tcdrain() hängen bleibt. Ich verstehe nur nicht warum. In der Vergangenheit ist das nie aufgetreten. Ich könnte noch prüfen, ob die vorherigen write() Aufrufe fehlerfrei abgearbeitet werden. Möglicherweise haben die 3.x.x Kernel einen USB-Bug.

Gruß
e9hack

softhddevice -> GrabImage

Jetzt mitmachen!

Teilen