Michael_K: Debugging Web Worker in Firefox

Bevor ich mich auf die Suche nach dem Fehler gebe, gibt es Tips bzgl. Debugging bei Web Workern?

Vermutlich ist es ein Bug in der Firefox-Engine, aber ich würde es gerne etwas eingrenzen, wo genau die Ursache liegt ... bevor ich es auf die Bugliste bei Mozilla setze.

Das Problem tritt nur im Firefox auf und ist zudem scheinbar auch "zufällig", d.h. es tritt bei Wiederholungen an unterschiedlichen Stellen auf.

Für eine komplexe Berechnung müssen mehrer Daten aus unterschiedlichen Dateien (über 100 Dateien) eingelesen werden. Für die Performance wird das Ganze in einen Web-Worker ausgelagert. Dieser Web-Worker started dann das Einlesen der Dateien, wobei für das Einlesen einer Datei wiederum ein eigener "Sub" Web-Worker genutzt wird, der sein Ergebnis zurückliefert und dann geschlossen wird. Diese "Sub" Web-Worker für eine einzelne Datei werden nicht alle gleichzeitig gestartet, sondern nur ein Anzahl X. Erst nachdem diese X "Sub" Web-Worker abgearbeitet sind, werden die nächsten gestartet, bis alle Daten aus den Dateien eingelesen wurden. Der erste Web-Worker liefert dann das Ergebnis an den Main-Thread zurück.

In Chromium basierten Browsern funktioniert es wunderbar und der Performancegewinn durch die Aufteilung in einzelne Web-Worker ist sehr gut.

Nur Firefox macht Probleme ... ohne erkennbare Fehler/Ursache. Firefox startet auch den ersten "Main" Web-Worker, der dann die anderen "Sub" Web-Worker parallel startet. Je nach Durchlauf stoppt Firefox aber an unterschiedlicher Stelle bei einem Durchlauf, d.h. nach unterschiedlicher Anzahl von eingelesenen Dateien. Es scheint ganz so, als ob der "Main" Web-Worker irgendwann keine neuen "Sub" Web-Worker starten kann. Wie gesagt, je nach Durchlauf nach unterschieldicher Anzahl von bereits eingelesenen Dateien. Also nicht immer nach einer bestimmten Anzahl von Dateien oder nach einer bestimmten Datei.

Debugging ist schwierig. Kann man die Web-Worker irgendwie markieren, sodass man nachvolluziehen kann, ob ein Web-Worker gestartet wurden und wenn nicht, warum er nicht gestartet wurde? Ich bekomme keine Fehlermeldungen am Error-Listener.

Bin für jeden Tipp bzw. Literatur dankbar. Gruss

  1. Hallo Michael_K,

    JavaScript gibt Dir wenig Chancen, mit Workern in eine Race-Condition zu laufen, aber es klingt irgendwie doch danach.

    Ich habe in JavaScript keine Erfahrung mit massiv parallelen Workern, ich habe bisher nur in C# etwas ähnliches gemacht und weiß, dass das korrekte Orchestrieren einer Worker-Meute im Computer genauso schwierig ist wie im echten Leben.

    Es scheint ganz so, als ob der "Main" Web-Worker irgendwann keine neuen "Sub" Web-Worker starten kann.

    Kann? Oder will? Weil er vielleicht nicht mitbekommen hat, dass ein Worker zu Ende ist? Bei massiv parallelen Vorgängen ist Debugging schwierig, weil ein Breakpoint das Timing verändert. Ich würde mit console.log() arbeiten und jeder Meldung den Namen des Workers voranstellen.

    Hast Du überhaupt schon geschaut, ob in der Konsole Fehlermeldungen stehen? Möglicherweise verwendest Du ein Feature, das Firefox (noch) nicht hat und du hast Laufzeitabbrüche.

    Rolf

    --
    sumpsi - posui - obstruxi
    1. Hallo Rolf,

      eine race condition kann ich eigentlich ausschliessen. Ich habe mit einer Einstellung getestet, die jeweils nur ein Sub Web Worker erstellt. Und ein nicht unterstütztes feature kann es nicht sein, da Firefox bei Wiederholungen an unterschiedlichen Stellen aufhört. Das heisst, manchmal schafft er 80 Dateien, beim nächsten Versuch schafft er nur 60 Dateien usw. Das ist ja gerade das wunderliche. Ich werde mich heute Abend noch einmal dransetzen und debugging fortsetzen.

      Das Orchestrieren erfolgt in einem Object im Main Web Worker. Als Beispiel:

      const fileObject = {
      "file1"; {"status":"waiting", "url": "..."},
      "file2"; {"status":"waiting", "url": "..."},
      "file3"; {"status":"waiting", "url": "..."},
      }
      

      Main Worker prüft, ob noch files mit status "waiting" bestehen. Wenn ja, wird ein Sub Web Worker für das File gestartet und im Object der Status auf "processing" gesetzt, also so:

      const fileObject = {
      "file1"; {"status":"processing", "url": "..."},
      "file2"; {"status":"waiting", "url": "..."},
      "file3"; {"status":"waiting", "url": "..."},
      }
      

      Wenn der Sub Web Worker fertig ist und sich mit dem Ergebnis und der fileID meldet, wird der status auf "finish" gesetzt:

      const fileObject = {
      "file1"; {"status":"finished", "url": "..."},
      "file2"; {"status":"waiting", "url": "..."},
      "file3"; {"status":"waiting", "url": "..."},
      }
      

      Und nach dem setzten von finished fängt es von vorne an, dass der Main Web Worker prüft, ob es noch files mit "waiting" gibt. Sofern alle Einträge den Status "finished" haben, sendet der Main Web Worker sein Ergebnis zurück an den Main Thread.

      Eigentlich ist das ziemlich robust umgesetzt. Ich werde jetzt wohl tatsächlich in den Sub Web Worker console.log Einträge anbringen um zu verstehen, ob der Worker für eine fileID gestartet und wenn ja, wie weit er gekommen ist.

      Mal schauen, ob ich die Ursache finde.

      Gruss

      1. Hallo Michael_K,

        nur zur Sicherheit dumm gefragt:

        • Die Kommunikation erfolgt über postMessage und das message-Event?
        • Verwendest Du irgendwelche Promises bzw. async/await-Konstrukte?

        Rolf

        --
        sumpsi - posui - obstruxi
        1. Hallo Rolf,

          ich nutze ein bereites Spektrum and Web-Techniken und ja, ich verwende postMessage und innerhalb der WebWorker auch async Methoden. Ich bin mir nun aber relativ sicher, dass es ein Bug im Firefox sein muss. Nachfolgend ein Beispielcode, der den Sachverhalt reproduziert.

          Könntest du eventuell mal testen, ob auch bei dir im Firefox der WebWorker an beliebiger Stelle auf einmal aufhört, die noch offenen Task abzuarbeiten? In der Console man nachvollziehen, wieviele Tasks abgearbeitet wurden. Chrome/Chromium läuft sauber durch und arbeitet alle ab. Firefox bricht an eine beliebigen Stelle ab.

          Hier der Code:

          Datei: index.html

          <html>
              <head>
                  <title>Web Worker test</title>
              </head>
              <body>
                  <button role="button" id="start">Start</button>
                  <div id="result"></div>
              </body>
              <script type="module" src="./index.js"></script>
          </html>
          

          Datei: index.js

          const runWorker = () => {
              let workerURL = new URL('./worker.js', import.meta.url);
              let worker = new Worker(workerURL, { type: "module" });
              worker.onmessage = ({ data: { cmd, result } }) => {
                  if (cmd == 'mainWorkerFinished') {
                      worker.terminate();
                      document.getElementById('result').innerHTML = JSON.stringify(result, null, null);
                  } else {
                      document.getElementById('result').innerHTML = 'unknown message';
                  }
              };
              worker.onerror = (error) => {
                  console.log('main worker error: ' + error.toString());
              };
              worker.postMessage({
                  cmd: 'runMainWorker'
              });
          }
          
          document.getElementById('start').addEventListener('click', () => {
              document.getElementById('result').innerHTML = 'running ...';
              runWorker();
          });
          

          Datei: worker.js

          let fileTask = {}
          
          const performTasks = () => {
              let waitingTask = Object.entries(fileTask).find(([fileID, entry]) => entry.status == 'waiting');
              if (waitingTask) {
                  let subWorkerURL = self.location.href;
                  let subWorker = new Worker(subWorkerURL, { type: "module" });
                  subWorker.onmessage = ({ data: { cmd, fileID } }) => {
                      switch (cmd) {
                          case 'subWorkerFinished': {
                              subWorker.terminate();
                              fileTask[fileID].status = 'finished';
                              console.log('finished ' + fileID);
                              performTasks();
                              break;
                          };
                          default: {
                              console.log('unknown command')
                          }
                      }
                  };
                  subWorker.onerror = (error) => {
                      console.log(error);
                  };
                  subWorker.postMessage({
                      cmd: "runSubWorker", fileID: waitingTask[0]
                  });
              } else {
                  // no more waiting tasks
                  self.postMessage({
                      cmd: "mainWorkerFinished", result: fileTask
                  })
              }
          }
          
          const runMainWorker = () => {
              // build large number of tasks
              let tasks = 70;
              while (tasks) {
                  fileTask['fileID_' + tasks] = {
                      status: "waiting"
                  }
                  tasks--;
              }
              performTasks();
          }
          
          const runSubWorker = async (fileID) => {
              // simulate async task and wait for 2 seconds
              await new Promise(r => setTimeout(r, 500));
              self.postMessage({
                  cmd: "subWorkerFinished", fileID
              });
          }
          
          self.onmessage = ({ data: { cmd, fileID } }) => {
              switch (cmd) {
                  case 'runMainWorker': {
                      runMainWorker();
                      break;
                  }
                  case 'runSubWorker': {
                      runSubWorker(fileID);
                      break;
                  }
                  default: {
                      console.log('unknown command');
                      self.terminate();
                  }
              }
          }
          
          1. Hallo Michael,

            ich habe Firefox für Windows 130.0.1 (64-Bit), und der arbeitet mit dem Code, den Du gepostet hast, die Liste gewissenhaft ab. Welchen hast Du?

            Update: Denkste. Beim 2. Versuch lief er nur bis 50.

            Rolf

            --
            sumpsi - posui - obstruxi
            1. Firefox 130.0 (64 Bit) Linux - Mozilla Firefox Snap for Ubuntu canonical 002 - 1.0

              16 GB RAM, 8 Core CPU

              Könntest es bitte noch 1 oder 2 mal wiederholen bzw. die Task-Anzahl von 70 auf 200 erhöhen?

              1. Hallo Michael,

                im Moment versuche ich, deinen Code zu verstehen. Dein echter Code muss anders aussehen, oder? Denn so, wie es jetzt aussieht, läuft zu einem Zeitpunkt nie mehr als ein Subworker gleichzeitig.

                Rolf

                --
                sumpsi - posui - obstruxi
                1. Ja, mein "echter" Code sieht leicht anders aus (d.h. leicht komplexer). Dieser Beispiel-Code ist einfacher, d.h. es wird immer nur ein Sub-Worker gestartet. Bei meinem echten Code werden mehrer Sub-Worker gleichzeitig gestartet. Die Anzahl der gleichzeitigen Sub-Worker bestimmt sich durch die CPU Cores. Immer wenn sich ein Sub-Worker mit dem Ergebnis zurück meldet, wird dann danach überprüft, ob es noch offene task gibt. Offene Task = task der gerade noch läuft oder task der noch nicht gestartet wurde.

                  Ergänzung: Wenn es keine offenen Task mehr gibt, sendet der Main Worker das Ergebnis zurück an den Main Thread.

                  Aber der Beispielcode reicht aus, um das Problem zu verdeutlichen. Das Prblem tritt scheinbar nicht mehr auf, wenn ich die Sub Worker an eine globale Variable im Main Worker binde.

                  1. Hallo Michael_K,

                    ja, und ich weiß jetzt auch, warum.

                    Es ist eine Race-Condition. In performTasks erzeugst Du den Subworker und registriert auf dem Subworker einen onmessage-Handler. Dieser soll das Ende des Subworkers feststellen.

                    In runSubWorker sendest Du dann die Ende-Nachricht.

                    Die Besonderheit ist, dass Du das hinter einem await tust. Das ist lediglich Syntaxzucker für einen Callback, den die .then-Methode eines Promise bekommt, und es bedeutet: alles, was hinter await folgt, läuft nicht mehr im normalen Ablauf der async-Funktion, sondern als Callback in der Microtask-Queue.

                    Aus Sicht der Browser-Runtime hängt das Worker-Objekt des Subworkers daher bereits an einem seidenen Faden. Es wird nicht gelöscht, weil es noch eine Referenz auf den await-Callback in der Mikrotask-Queue gibt, aber sobald dieser Callback durch ist, war's das und der Collector schlägt zu.

                    Damit ist das Subworker-Objekt weg, und es gibt nichts mehr, was es hält. Die performTasks-Funktion, die es erzeugt hatte, ist längst zu Ende und der onmessage-Callback, den Du da registrierst hast, hängt am Subworker-Objekt. Aber wenn das Objekt weg ist, gibt's auch keine Eventbehandlung mehr. Und je nach dem, wann der GC zuschlägt, lebt der Subworker lang genug um die Nachricht zu verarbeiten, oder auch nicht. Und dann ist der Ablauf zu Ende. Hat dein Originalcode auch eine async-Funktion für die Subworker?

                    Ich nehme an, dass die JS Runtime nach dem regulären Ende einer Worker-Funktion irgendwie sicherstellt, dass der letzte pushMessage-Aufruf des Workers noch verarbeitet wird. Wenn dieser letzte pushMessage-Aufruf aber aus einem Microtask kommt, klappt das nicht mehr. Zumindest nicht im Firefox. Die V8 Engine von Chrome scheint diesen Fall besser zu berücksichtigen.

                    Ich habe deine await-Verzögerer mal durch eine For-Schleife mit 100 Millionen durchläufen ersetzt. Die dauert dann ca 50ms - und damit laufen 200 Subworker problemlos durch. Eine await-Verzögerung mit 50ms bricht zuverlässig nach ca 100-150 Workern ab.

                    Wenn ich wieder auf deine await-Verzögerung zurückgehe, aber dann nach dem postMessage des subWorkerFinished eine weitere await-Verzögerung von 50ms mache, dann gibt es noch 50ms lang eine Referenz auf den Subworker, und das reicht, um zuverlässig die Antwort verarbeiten zu können.

                    Deine Lösung, die Subworker in einer globalen Variablen zu halten, funktioniert auch.

                    Du müsstest den Subworker-Code übrigens in einen try/finally einschließen und die Ende-Message im finally-Teil senden, damit Du bei einem Error im Subworker immer noch eine Rückmeldung bekommen kannst.

                    Was Du übrigens nicht zu tun brauchst, ist subworker.terminate(). Das ist nur nötig wenn Du Subworker abbrechen willst. Aber wenn Du die subWorkerFinished-Nachricht bekommst, ist er eh zu Ende.

                    Rolf

                    --
                    sumpsi - posui - obstruxi
                    1. Hallo Rolf,

                      vielen Dank für die Info. Es entspricht aber nicht meinem Verständnis der Specs. Es scheint ganz so, als dass Mozilla eine andere Interpretation der Specs hat. Ich habe nun noch einmal nachgelesen:

                      "A worker is said to be an active needed worker if any of its owners are either Document objects that are fully active or active needed workers.

                      A worker is said to be a protected worker if it is an active needed worker and either it has outstanding timers, database transactions, or network connections, or its list of the worker's ports is not empty, or its WorkerGlobalScope is actually a SharedWorkerGlobalScope object (i.e., the worker is a shared worker)."

                      Ich hatte damals auch irgendwo gelesen, dass ein Worker nicht geschlossen werden kann, wenn ein Listener active ist.

                      Was Du übrigens nicht zu tun brauchst, ist subworker.terminate(). Das ist nur nötig wenn Du Subworker abbrechen willst. Aber wenn Du die subWorkerFinished-Nachricht bekommst, ist er eh zu Ende.

                      Oh doch, das ist notwendig. Sonst bleiben die ganzen Web Worker offen. Man kann einen Worker von "innen" schliessen mit self.close() oder eben von "aussen" mit terminate(). Terminate ist aus meiner Erfahren sicherer bzw. einfacher. Wenn man den Worker nicht beendet, dann gibt es ein schönes memory leak, zumindest bei der V8 Engine (siehe in der Grafik rechts), die nach meinem Verständnis sich so verhält, wie es in den Specs steht. In meinem Beispielcode hätte ich den subWorker zum besseren Verständnis in eine separate Datei legen sollen, dann wird es noch transparenter, dass die sub Worker nicht geschlossen werden.

                      Bei FF scheint wirklich der GC zuzuschlagen, weil die Worker nicht mehr als actively needed angesehen werden.

                      Du müsstest den Subworker-Code übrigens in einen try/finally einschließen und die Ende-Message im finally-Teil senden, damit Du bei einem Error im Subworker immer noch eine Rückmeldung bekommen kannst.

                      Das Beispiel war stark abstrahiert. Im echten Code ist sichergestellt, dass der Worker wieder zurückfunkt, sei es bei einem Fehler oder wenn fertig.

                      Ich kann jetzt erst einmal weitermachen, werde aber von nun an einen Web Worker immer global binden und manuell steuern steuern. Werde deshalb künftig immer noch eine WorkerID erstellen, die dann via postMessage immer mit ausgetauscht wird.

                      1. Hallo Michael_K,

                        A worker is said to be an active needed worker if any of its owners are either Document objects that are fully active or active needed workers.

                        A worker is said to be a protected worker if it is an active needed worker and either it has outstanding timers, database transactions, or network connections

                        Das ist alles Spec-gobbledygook, bestehend aus eine Menge von selbsterfundenen Begriffen, die kreuz und quer aufeinander verweisen. D.h. man hat schnell mal nur die Hälfte der relevanten Teile gelesen. Mir werden diese Begriffe NICHT klar.

                        Was ich aber beobachten kann, dass der FF keine Probleme mehr macht, wenn man dem Thread nach dem Senden der Antwort eine gewisse Schonfrist gewährt. Ich muss im FF nochmal betrachten, wie der die Worker-Threads abräumt. Chrome tut es nicht, da hast Du leider recht, die Subworker bleiben hängen bis entweder der MainWorker gekillt wird oder bis der Mainworker sie explizit killt.

                        Leider kann man die entscheidenden Informationen auch nicht sehen. Z.B. das closing-Flag, von dem die Spec spricht. Das ist intern und lässt sich nicht debuggen.

                        Eins solltest Du aber auf jeden Fall noch ändern: terminate() ist die Notlösung für wildgewordene Worker. Eigentlich sollte ein Worker, der weiß, dass er fertig ist, self.close() aufrufen.

                        Rolf

                        --
                        sumpsi - posui - obstruxi
                        1. Hallo Rolf

                          Eins solltest Du aber auf jeden Fall noch ändern: terminate() ist die Notlösung für wildgewordene Worker. Eigentlich sollte ein Worker, der weiß, dass er fertig ist, self.close() aufrufen.

                          Was waere das Hauptargument hierfuer? Ich habe auch gelesen, das self.close() die "gracefully methode" ist und terminate die Methode mit dem Vorschlaghammer. Ich verwende inzwischen aber tatsaechlich nur noch terminate() aus den folgenden Gruenden

                          • Es ist unuebersichtlicher, wenn das Beenden eines Workers an verschiedenen Code-Stellen ( bei ESM oft in unterschiedlichen Modulen ) hinterlegt ist.
                          • Ich habe mir angewoehnt, immer Kontext bei postMessage mitzugeben (wie im Beispiel hinterlegt die Art der Message mit dem Key "cmd"). Das hat den Vorteil, dass am Listener an einer Stelle hinterlegt werden kann, ob der Worker je nach Art der Message zu beenden ist.
                          • Ich hatte festgestellt, dass ein self.close() den Worker scheinbar nicht zwingend unmittelbar beendet. Zum Beispiel, wenn in einem Worker mehrere async Aufrufe noch laufen, dann hat self.close() gewartet, bis alle abgearbeitet wurden - zumindest habe ich es so in Erinnerung, als ich mit Web Workern getestet hatte. Ob es immer noch so ist, weiss ich nicht. Aber oft besteht kein Interesse, dass der Worker noch unnoetig lange offen ist und arbeitet.

                          Gruss Michael

                          1. Hallo Michael_K,

                            Zum Beispiel, wenn in einem Worker mehrere async Aufrufe noch laufen, dann hat self.close() gewartet, bis alle abgearbeitet wurden

                            Aber ist das nicht das, was Du willst? Kann es laufende async-Aufrufe geben (oder anders gesagt: unaufgelöste Promises), wenn der Worker mit seinem Job fertig ist? Das widerspricht sich aus meiner Sicht. Es kann doch nicht sein, dass der Worker eine Arbeit in Auftrag gibt und dann spontan entscheidet, dass er das Ergebnis doch nicht braucht. Das ist ein Worker, kein wankelmütiger Kunde!

                            Rolf

                            --
                            sumpsi - posui - obstruxi
            2. Danke für die Bestätigung!!!

              Genau das meine ich mit "zufällig". Ich werde mal einen Bug Report am Wochenende erstellen.

        2. Ich glaube, ich habe die Antwort/Lösung gefunden. Wenn ich den jeweiligen SubWorker an eine globale Variable hänge, dann arbeitet Firefox scheinbar auch vollständige die Task-Liste ab.

          Kann es sein, dass bei Firefox der Garbage Collector zuschlägt? Das würde auch erklären, warum es an "zufälliger" Stelle aufhört. Sollte man das Mozilla melden. Ich konnte nichts finden, wie die Firefox JS Engine mit Workern umgeht, die in einer Funktion hängen und nur einen Listener besitzen, aber ansonsten keine weiteren Datenverknüpfungen.

          PS: Ich habe auch die eigentliche JS-Biblithek angepasst, d.h. den SubWorker jeweils an ein globales Object im MainWorker angehangen. Funktioniert nun auch einwandfrei in Firefox. Scheint wirklich so, dass der Garbage Collector unterschiedlich bei Firefox und Chrome implementiert ist. Ich war davon ausgegangen, dass ein Worker innerhalb einer Funktion am Leben bleibt, wenn dieser Worker auf ein Event hört. Bin aber erleichtert, dass ich nun die Ursache gefunden habe.