small medium large xlarge

Generic-user-small
20 Feb 2017, 02:46
Eduardo Chapa (3 posts)

Hello, first of all I’m loving this book.

When I finished coding my version of zmq-push-cluster.js I then compared it to the version provided in the source examples and realized that I wrote the line to address “If the message is a result message, output it to the console.” a little different, which caused my worker results to look as if they were queued when written to the console, instead of showing parallelism like in the example’s result.

The code used in the example zmq-push-cluster.js on line 42 is:

console.log('received: ' + data);

The console output of the example is the following, which seems ok:

Worker 4219 is online.
Worker 4217 is online.
Worker 4218 is online.
4219 received job: 0
4218 received job: 2
4219 received job: 3
4217 received job: 1
received: {"index":0,"pid":4219,"result":"success"}
received: {"index":2,"pid":4218,"result":"success"}
4219 received job: 6
4219 received job: 9
4219 received job: 12
4219 received job: 15
received: {"index":3,"pid":4219,"result":"success"}
received: {"index":1,"pid":4217,"result":"success"}
4219 received job: 18
4218 received job: 5
received: {"index":6,"pid":4219,"result":"success"}
received: {"index":9,"pid":4219,"result":"success"}
4219 received job: 21
received: {"index":12,"pid":4219,"result":"success"}
received: {"index":15,"pid":4219,"result":"success"}
4219 received job: 24
received: {"index":18,"pid":4219,"result":"success"}
received: {"index":21,"pid":4219,"result":"success"}
4219 received job: 27
4218 received job: 8
4217 received job: 4
4218 received job: 11
4218 received job: 14
received: {"index":24,"pid":4219,"result":"success"}
4218 received job: 17
received: {"index":5,"pid":4218,"result":"success"}
received: {"index":27,"pid":4219,"result":"success"}
4218 received job: 20
received: {"index":8,"pid":4218,"result":"success"}
received: {"index":11,"pid":4218,"result":"success"}
received: {"index":14,"pid":4218,"result":"success"}
4218 received job: 23
received: {"index":17,"pid":4218,"result":"success"}
4218 received job: 26
received: {"index":20,"pid":4218,"result":"success"}
4217 received job: 7
received: {"index":23,"pid":4218,"result":"success"}
4218 received job: 29
received: {"index":4,"pid":4217,"result":"success"}
4217 received job: 10
received: {"index":26,"pid":4218,"result":"success"}
4217 received job: 13
4217 received job: 16
received: {"index":7,"pid":4217,"result":"success"}
4217 received job: 19
received: {"index":29,"pid":4218,"result":"success"}
received: {"index":10,"pid":4217,"result":"success"}
4217 received job: 22
received: {"index":13,"pid":4217,"result":"success"}
4217 received job: 25
received: {"index":16,"pid":4217,"result":"success"}
4217 received job: 28
received: {"index":19,"pid":4217,"result":"success"}
received: {"index":22,"pid":4217,"result":"success"}
received: {"index":25,"pid":4217,"result":"success"}
received: {"index":28,"pid":4217,"result":"success"}

But for that line I’m using the following code - which uses the parsed message instead of the original data variable from the function:

console.log("Result: ", message);

This results in the following console output:

Worker 4225 is online.
Worker 4226 is online.
Worker 4227 is online.
4227 received job: 2
4226 received job: 1
4225 received job: 0
4226 received job: 4
4225 received job: 3
4227 received job: 5
4225 received job: 6
4226 received job: 7
4225 received job: 9
4226 received job: 10
4225 received job: 12
4226 received job: 13
4225 received job: 15
4226 received job: 16
4225 received job: 18
4227 received job: 8
4226 received job: 19
4225 received job: 21
4227 received job: 11
4226 received job: 22
4225 received job: 24
4227 received job: 14
4226 received job: 25
4225 received job: 27
4227 received job: 17
4226 received job: 28
4227 received job: 20
4227 received job: 23
4227 received job: 26
4227 received job: 29
received:  { index: 2, pid: 4227, result: 'success' }
received:  { index: 1, pid: 4226, result: 'success' }
received:  { index: 0, pid: 4225, result: 'success' }
received:  { index: 5, pid: 4227, result: 'success' }
received:  { index: 4, pid: 4226, result: 'success' }
received:  { index: 3, pid: 4225, result: 'success' }
received:  { index: 8, pid: 4227, result: 'success' }
received:  { index: 7, pid: 4226, result: 'success' }
received:  { index: 6, pid: 4225, result: 'success' }
received:  { index: 11, pid: 4227, result: 'success' }
received:  { index: 10, pid: 4226, result: 'success' }
received:  { index: 9, pid: 4225, result: 'success' }
received:  { index: 14, pid: 4227, result: 'success' }
received:  { index: 13, pid: 4226, result: 'success' }
received:  { index: 12, pid: 4225, result: 'success' }
received:  { index: 17, pid: 4227, result: 'success' }
received:  { index: 16, pid: 4226, result: 'success' }
received:  { index: 15, pid: 4225, result: 'success' }
received:  { index: 20, pid: 4227, result: 'success' }
received:  { index: 19, pid: 4226, result: 'success' }
received:  { index: 18, pid: 4225, result: 'success' }
received:  { index: 23, pid: 4227, result: 'success' }
received:  { index: 22, pid: 4226, result: 'success' }
received:  { index: 21, pid: 4225, result: 'success' }
received:  { index: 26, pid: 4227, result: 'success' }
received:  { index: 25, pid: 4226, result: 'success' }
received:  { index: 24, pid: 4225, result: 'success' }
received:  { index: 29, pid: 4227, result: 'success' }
received:  { index: 28, pid: 4226, result: 'success' }
received:  { index: 27, pid: 4225, result: 'success' }

My question is why that single change seems to be affecting the parallelism or flow of the program on my version.

I’m using node v7.5.0 on OS X.

Thanks in advance, Eduardo

Generic-user-small
20 Feb 2017, 06:09
Eduardo Chapa (3 posts)

Weirdly enough, I just tested both versions of the code on Linux and their output is almost identical, except for the double quotes on the JSON messages.

This is the result from the example source code on Linux:

Worker 8938 is online.
Worker 8939 is online.
Worker 8945 is online.
8938 received job: 0
received: {"index":0,"pid":8938,"result":"success"}
8939 received job: 1
8945 received job: 2
received: {"index":1,"pid":8939,"result":"success"}
received: {"index":2,"pid":8945,"result":"success"}
8938 received job: 3
8939 received job: 4
received: {"index":4,"pid":8939,"result":"success"}
received: {"index":3,"pid":8938,"result":"success"}
8938 received job: 6
received: {"index":6,"pid":8938,"result":"success"}
8939 received job: 7
received: {"index":7,"pid":8939,"result":"success"}
8939 received job: 10
received: {"index":10,"pid":8939,"result":"success"}
8938 received job: 9
received: {"index":9,"pid":8938,"result":"success"}
8939 received job: 13
received: {"index":13,"pid":8939,"result":"success"}
8938 received job: 12
received: {"index":12,"pid":8938,"result":"success"}
8938 received job: 15
received: {"index":15,"pid":8938,"result":"success"}
8939 received job: 16
received: {"index":16,"pid":8939,"result":"success"}
8938 received job: 18
received: {"index":18,"pid":8938,"result":"success"}
8945 received job: 5
received: {"index":5,"pid":8945,"result":"success"}
8939 received job: 19
received: {"index":19,"pid":8939,"result":"success"}
8939 received job: 22
received: {"index":22,"pid":8939,"result":"success"}
8938 received job: 21
received: {"index":21,"pid":8938,"result":"success"}
8938 received job: 24
received: {"index":24,"pid":8938,"result":"success"}
8939 received job: 25
received: {"index":25,"pid":8939,"result":"success"}
8945 received job: 8
8938 received job: 27
received: {"index":27,"pid":8938,"result":"success"}
8939 received job: 28
received: {"index":28,"pid":8939,"result":"success"}
received: {"index":8,"pid":8945,"result":"success"}
8945 received job: 11
received: {"index":11,"pid":8945,"result":"success"}
8945 received job: 14
received: {"index":14,"pid":8945,"result":"success"}
8945 received job: 17
received: {"index":17,"pid":8945,"result":"success"}
8945 received job: 20
received: {"index":20,"pid":8945,"result":"success"}
8945 received job: 23
received: {"index":23,"pid":8945,"result":"success"}
8945 received job: 26
received: {"index":26,"pid":8945,"result":"success"}
8945 received job: 29
received: {"index":29,"pid":8945,"result":"success"}

And this is the result from my version with console.log("Result: ", message) :

Worker 3231 is online.
Worker 3232 is online.
Worker 3238 is online.
3231 received job: 0
received:  { index: 0, pid: 3231, result: 'success' }
3231 received job: 3
received:  { index: 3, pid: 3231, result: 'success' }
3231 received job: 6
received:  { index: 6, pid: 3231, result: 'success' }
3231 received job: 9
received:  { index: 9, pid: 3231, result: 'success' }
3231 received job: 12
received:  { index: 12, pid: 3231, result: 'success' }
3231 received job: 15
received:  { index: 15, pid: 3231, result: 'success' }
3231 received job: 18
received:  { index: 18, pid: 3231, result: 'success' }
3231 received job: 21
received:  { index: 21, pid: 3231, result: 'success' }
3231 received job: 24
received:  { index: 24, pid: 3231, result: 'success' }
3231 received job: 27
received:  { index: 27, pid: 3231, result: 'success' }
3232 received job: 2
3238 received job: 1
received:  { index: 2, pid: 3232, result: 'success' }
received:  { index: 1, pid: 3238, result: 'success' }
3232 received job: 5
received:  { index: 5, pid: 3232, result: 'success' }
3238 received job: 4
3232 received job: 8
received:  { index: 8, pid: 3232, result: 'success' }
received:  { index: 4, pid: 3238, result: 'success' }
3232 received job: 11
received:  { index: 11, pid: 3232, result: 'success' }
3232 received job: 14
received:  { index: 14, pid: 3232, result: 'success' }
3238 received job: 7
received:  { index: 7, pid: 3238, result: 'success' }
3232 received job: 17
received:  { index: 17, pid: 3232, result: 'success' }
3232 received job: 20
received:  { index: 20, pid: 3232, result: 'success' }
3238 received job: 10
received:  { index: 10, pid: 3238, result: 'success' }
3238 received job: 13
received:  { index: 13, pid: 3238, result: 'success' }
3232 received job: 23
received:  { index: 23, pid: 3232, result: 'success' }
3238 received job: 16
received:  { index: 16, pid: 3238, result: 'success' }
3232 received job: 26
received:  { index: 26, pid: 3232, result: 'success' }
3238 received job: 19
received:  { index: 19, pid: 3238, result: 'success' }
3232 received job: 29
3238 received job: 22
received:  { index: 22, pid: 3238, result: 'success' }
received:  { index: 29, pid: 3232, result: 'success' }
3238 received job: 25
received:  { index: 25, pid: 3238, result: 'success' }
3238 received job: 28
received:  { index: 28, pid: 3238, result: 'success' }
Avatar_pragsmall
22 Feb 2017, 12:06
Jim R. Wilson (85 posts)

How interesting!

The reason for the difference in quote style is that the message data itself is JSON encoded, whereas console.log() uses util.inspect()[1] to stringify objects. If the objects were much deeper (that is, maps of maps etc. rather than just a simple key/value map), it would truncate the output rather than continuing.

As to the timing difference, my guess is that it has to do with the cost of having to call out to util.inspect to perform the serialization. Note however that even though the console statements are not interleaved, the PIDs are dispersed, meaning you’re not falling subject to the first joiner problem. :)

[1] https://nodejs.org/api/util.html#util_util_inspect_object_options

Generic-user-small
23 Mar 2017, 23:04
Eduardo Chapa (3 posts)

Thank you very much for the explanation!

You must be logged in to comment