What order do things happen in streams in node.js

Question

I'm trying to understand what order things happen in node.js streams. The script I'm running takes a collection of name/email pairs, runs over that collection, creates a couchdb entry for each, then generates a QR code and inserts it in that couchdb entry.

Here's the code:

/*
 * This script takes a collection of names/emails and creates tickets for them.
 */

// Connect to Couch.
var db = require('nano')('https://' + process.env.USER + ':' + process.env.PASS + '@' + process.env.COUCH);

// Load QR Generator.
var qr = require('qr-image');

// Who to email?
var people = [
  { name: 'Katie', email: 'katie@*****.com' },
  { name: 'Alex', email: 'alex@*****.com' },
  { name: 'Kelsey', email: 'kelsey@*****.com' }
];

var tix = 0;

// For Each preson in the above list,
people.forEach(function (person, index, array) {

  // (1) assemble a grit-ticket doc for couch,
  var ticket = {
    "name": person.name,
    "email": person.email,
    "purchaser": "complimentary",
    "type": "ticket"
  };

  // (2) insert that doc into CouchDB,
  db.insert(ticket, function (error, doc, headers) {
    if (error) return console.log("Couch Error: ", error, "Headers: ", headers);

    // (3)  make a QR code,
    var code = qr.image('https://tedxgramercy.com/attendee?id=' + doc.id, { type: 'png' });

    // (4) add that QR code to the doc,
    code.pipe( db.attachment.insert(doc.id, 'qr-code.png', null, 'image/png', { rev: doc.rev }, function (err, reply) {
      if (err) { return console.log("Couch image error: ", err) }
      console.log("Couch image reply: ", reply);
    }) );
    code.on('end', function (error) {
      if (error) { return console.log('QR Submition', [error]) }
      tix += 1;

      // (5) Report out success.
      console.log(tix + " tickets created successfully.");

    });

  });

});

What I got when I ran this script (with 6 emails, not just three) was this:

$ node makeTix.js 
1 tickets created successfully.
2 tickets created successfully.
3 tickets created successfully.
4 tickets created successfully.
5 tickets created successfully.
Couch image reply:  { ok: true,
  id: '8e15d0676ec8d9f686ebbd38237a',
  rev: '2-f03610b92d3461fc9c167f2405e7a2d0' }
6 tickets created successfully.
Couch image reply:  { ok: true,
  id: '8e15d0676ec8d9f8f686ebbd3823806e',
  rev: '2-eb0f676e4ed6f7203420a4864357e3f8' }
Couch image reply:  { ok: true,
  id: '8e15d0676ec8d9f8f686ebbd38236158',
  rev: '2-038c68f6d57b1925c0353fca3b2d59c1' }
Couch image reply:  { ok: true,
  id: '8e15d0676ec8d9f8f686ebbd382364a7',
  rev: '2-9a19a3cd4b8cff2ae2b38cf000dd0aaf' }
Couch image reply:  { ok: true,
  id: '8e15d0676ec8d9f8f686ebbd38236fb4',
  rev: '2-40c0ccc77c07f470424958e6d6e88a9b' }
Couch image reply:  { ok: true,
  id: '8e15d0676ec8d9f8f686ebbd38236174',
  rev: '2-ac78e326b9898d4a340228faa63167e1' }

All I'm trying to understand is why I get the logs in this half-staggered kind of order, rather than one "Couch image reply" followed by one "# tickets created successfully."

Any help would rock!

Update Ahhhh, I'm learning : ) Ok, so all the of forEach functions fire at once. Go Node! That's ridiculous. Okay, one question left...

How can I get "# tickets posted successfully" log to only fire if there's a non-error reply for the image insert? Can I put the code.on('end') inside the couchdb callback? No no, that's within the pipe that would be super confusing.... I's a bit lost.

I had forgotten to add the console log for the successful doc entry, that makes things even more staggered and weird. — Costa Michailidis, Sep 24 '14 at 15:12
If you want to post the complete log, I can explain it for you : ) — DrakaSAN, Sep 24 '14 at 15:20
@DrakaSAN answer covers the issue, but you might also want to review [this answer](http://stackoverflow.com/questions/4506240/understanding-the-concept-of-javascript-callbacks-with-node-js-especially-in-lo?rq=1) which I found useful when grappling with this sort of thing. — Matthew Bakaitis, Sep 24 '14 at 15:24
Ohhh, I think I'm clear. All of the forEach's fire, so in theory I should get one of each log and then the next forEach instance, but they're coming in as fast as possible, logging whatever's done whenever it's done. Ah, "I see said the blind man." So then, one last question, how can I get "# tickets posted successfully" to only fire is there's a non-error reply for the image insert? — Costa Michailidis, Sep 24 '14 at 15:34

DrakaSAN · Accepted Answer · 2014-09-25T07:48:06.690

Node.js is asynchronous, that s the reason you see this behavior, streams has nothing to do with that. (credit to MatthewBakaitis for the stream part).

Every callback (or should I say, every asynchronous function) is basically "Hey computer, do that and call me when you re done", so that everything happens (from user view) at the same time. ForEach is asynchronous, db.insert too, so what happen in your code is basically:

//For each people, send a request to the computer to do that function
people.forEach(function (person, index, array) {
//Synchronous part, then
//Hey, send this data to the db for me, and call me when you re done
db.insert(ticket, function (error, doc, headers) {
//Once data is inserted
//Synchronous part
//When pipe happen, do this
code.pipe
//When finished, do this
code.on('end'

So with the six people, what happen is:

forEach start function for people 1
forEach start function for people 2
forEach start function for people 3
forEach start function for people 4
forEach start function for people 5
In the meantime, function has ended for 1, so execute the callback
forEach start function for people 1
function has ended for 2, so execute the callback
function has ended for 3, so execute the callback
function has ended for 4, so execute the callback
function has ended for 5, so execute the callback
function has ended for 6, so execute the callback

It s kind of difficult to apprehend that, you just need to accept that eveything will be done in the same time.

Update:

Althought forEach is asynchronous, it will "lock" the code to whatever happen inside before letting the code continue, so:

forEach(function (element) {
    //Asynchronous code and calculing tx
});
console.log(tx + ' ticket created successfully);

should do the trick.

It's also worth adding that this has nothing to do with streams. The behavior that @Costa is seeing is solely from the asynchronous callback from `db.insert`. — Matthew Bakaitis, Sep 24 '14 at 15:20
I'm familiar with the asynchronisity of node, it's the stream syntax of code.pipe that's a bit confusing. My console logs are inside of nested callbacks, so my feeling was that they shouldn't be logged until those callbacks fire. — Costa Michailidis, Sep 24 '14 at 15:31

What order do things happen in streams in node.js

1 Answers1