NodeJS - Datenereignisse aus lesbarem Stream ohne entsprechende Pause aus beschreibbarem Stream anzeigen

Wir sehen eine extrem hohe Speichernutzung bei einigen unserer Streams in der Produktion. Die Dateien werden in S3 gespeichert, und wir öffnen einen lesbaren Stream für das S3-Objekt. Anschließend leiten wir diese Daten an eine Datei in unserem lokalen Dateisystem (auf unserer EC2-Instanz) weiter. Einige unserer Kunden haben extrem große Dateien. In einem Fall hatten sie eine Datei mit einer Größe von über 6 GB, und der Knotenprozess, der diese Datei handhabte, verwendete so viel Speicher, dass wir fast den gesamten Auslagerungsspeicher ausschöpften und der Computer zu einem Crawl verlangsamte. Offensichtlich gibt es irgendwo ein Speicherleck, das ich aufzuspüren versuche.

In der Zwischenzeit habe ich unseren Code etwas erweitert, um zu protokollieren, wenn wir bestimmte Ereignisse aus den Streams sehen. Ich habe den Code unten und einige Beispielausgaben aus dem Protokoll mit einer kleinen Testdatei. Was mich verwirrt, ist die Tatsache, dass der lesbare Stream ein Pausenereignis empfängt und dann weiterhin Daten ausgibt und Ereignisse pausiertOHN Der beschreibbare Stream gibt ein Drain-Ereignis aus. Fehlt mir hier etwas komplett? Wie werden nach dem Anhalten des lesbaren Streams weiterhin Datenereignisse gesendet, bevor ein Drain empfangen wird? Der beschreibbare Stream hat noch nicht angegeben, dass er bereit ist. Der lesbare Stream sollte also nichts senden ... oder?

Schauen Sie sich doch die Ausgabe an. Die ersten 3 Ereignisse machen für mich Sinn: Daten, Pause, Abfluss. Dann sind die nächsten 3 in Ordnung: Daten, Daten, Pause. DANN sendet es aber noch ein Daten- und ein Pausenereignis aus, bevor es schließlich als neuntes Ereignis abläuft. Ich verstehe nicht, warum die Ereignisse 7 und 8 aufgetreten sind, da der Abfluss erst nach dem 9. Ereignis erfolgt. Andererseits gibt es nach dem 9. Ereignis eine Reihe von Daten / Pausen-Paaren ohne entsprechenden Abfluss. Warum? Was ich erwarten würde, ist eine Anzahl von Datenereignissen, dann eine Pause und dannNICHT bis ein Drain-Ereignis auftritt - an diesem Punkt können erneut Datenereignisse auftreten. Es scheint mir, dass nach einer Pause überhaupt keine Datenereignisse auftreten sollten, bis ein Drain-Ereignis ausgelöst wird. Vielleicht verstehe ich etwas über Node-Streams immer noch grundlegend falsch?

UPDATE: Die Dokumente erwähnen nichts über ein Pause-Ereignis, das von lesbaren Streams ausgegeben wird, aber sie erwähnen, dass eine Pause-Funktion verfügbar ist. Vermutlich wird dies aufgerufen, wenn der beschreibbare Stream false zurückgibt, und ich würde annehmen, dass die Pausenfunktion das Pause-Ereignis auslösen würde. Wenn pause () aufgerufen wird, scheinen die Dokumente auf jeden Fall mit meiner Sicht der Welt zu harmonieren. Sehenhttps: //nodejs.org/docs/v0.10.30/api/stream.html#stream_class_stream_readabl

Diese Methode bewirkt, dass ein Stream im Fließmodusstop emittierende Daten Veranstaltunge. Alle Daten, die verfügbar werden, verbleiben im internen Puffer.

Dieser Test wurde auf meinem Entwicklungscomputer (Ubuntu 14.04 mit Node v0.10.37) ausgeführt. Unsere EC2-Instanzen in prod sind fast gleich. Ich denke, sie laufen jetzt v0.10.30.

S3Service.prototype.getFile = function(bucket, key, fileName) {
  var deferred = Q.defer(),
    self = this,
    s3 = self.newS3(),
    fstream = fs.createWriteStream(fileName),
    shortname = _.last(fileName.split('/'));

  logger.debug('Get file from S3 at [%s] and write to [%s]', key, fileName);

  // create a readable stream that will retrieve the file from S3
  var request = s3.getObject({
    Bucket: bucket,
    Key: key
  }).createReadStream();

  // if network request errors out then we need to reject
  request.on('error', function(err) {
      logger.error(err, 'Error encountered on S3 network request');
      deferred.reject(err);
    })
    .on('data', function() {
      logger.info('data event from readable stream for [%s]', shortname);
    })
    .on('pause', function() {
      logger.info('pause event from readable stream for [%s]', shortname);
    });

  // resolve when our writable stream closes, or reject if we get some error
  fstream.on('close', function() {
      logger.info('close event from writable stream for [%s] -- done writing file', shortname);
      deferred.resolve();
    })
    .on('error', function(err) {
      logger.error(err, 'Error encountered writing stream to [%s]', fileName);
      deferred.reject(err);
    })
    .on('drain', function() {
      logger.info('drain event from writable stream for [%s]', shortname);
    });

  // pipe the S3 request stream into a writable file stream
  request.pipe(fstream);

  return deferred.promise;
};

[2015-05-13T17:21:00.427Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.427Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.427Z] INFO: worker/7525 on bdmlinux: drain event from writable stream for [FeedItem.csv] [2015-05-13T17:21:00.507Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.514Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.515Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.515Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.515Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.515Z] INFO: worker/7525 on bdmlinux: drain event from writable stream for [FeedItem.csv] [2015-05-13T17:21:00.595Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.596Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.596Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.596Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.597Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.597Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.597Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.597Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.598Z] INFO: worker/7525 on bdmlinux: drain event from writable stream for [FeedItem.csv] [2015-05-13T17:21:00.601Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.602Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.602Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.602Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.603Z] INFO: worker/7525 on bdmlinux: drain event from writable stream for [FeedItem.csv] [2015-05-13T17:21:00.627Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.627Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.627Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.628Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.628Z] INFO: worker/7525 on bdmlinux: drain event from writable stream for [FeedItem.csv] [2015-05-13T17:21:00.688Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.689Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.689Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.689Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.690Z] INFO: worker/7525 on bdmlinux: data event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.690Z] INFO: worker/7525 on bdmlinux: pause event from readable stream for [FeedItem.csv] [2015-05-13T17:21:00.691Z] INFO: worker/7525 on bdmlinux: close event from writable stream for [FeedItem.csv] -- done writing file

Antworten auf die Frage(2)

Ihre Antwort auf die Frage