What the heck?

Levi Pearson levipearson at gmail.com
Thu Dec 12 16:11:00 MST 2013

On Thu, Dec 12, 2013 at 12:30 PM, S. Dale Morrey <sdalemorrey at gmail.com> wrote:

> The function spewing this out is an iterator that is calling setTimeout to
> run these requests with about 500ms of delay (so as not to swamp the server
> I'm getting the request from.  Once it has the result of the block hash it
> should be feeding it to a message queue, but it's not.
> I would expect that at sometime during this process the timer would fire
> and I should see debug spew from the function being called by the timer.
>  Fact is that I'm not.
> Here is the function itself...
> function blockCountCallBack(err, blockcount){
>     console.log("BlockCount: ", blockcount);
>     for(var i = lastblock; i < blockcount; i++){
>         //Multiplex across multiple clients so we don't overwhelm a single
> server
>         blockDB.put("lastblock",i);
>         var clientnum = 0;
>         if(i >= clients.length){
>           clientnum = i%clients.length;
>         }
>         console.log("Setting up "+i+" of "+blockcount+" block hash
> requests.");
>         setTimeout(function(){
>                 clients[clientnum].getBlockHash(i,addBlockToMessage);
>         },500);
>     }
> }

There are a number of issues here.  First of all, it's important to
understand Javascript's scoping rules, which are stupid.

There are two basic scopes, global scope and function scope.  These
rules determine which scope a variable belongs to:

1. A variable that is used without being declared in the function it's
being used (or an immediately enclosing function) in is implicitly a
global variable.

2. Any variable declared with 'var' outside of a function is a global variable.

3. Any variable declared with 'var' *anywhere* within a function is
in-scope *everywhere* in the immediately enclosing function.

4. There is no "block" scope.  Variables declared within a block are
in scope throughout the enclosing function.

A freakish twist on rule 3 is that although the variable is in scope
everywhere in a function, it is not *initialized* until execution
reaches the point where it's assigned a value.  Before that, it holds
the value 'undefined'.

Also from rule 3, there is only a single 'clientnum' variable and a
single 'i' variable defined, and they are in scope throughout the
entire blockCountCallBack function.

Now, regarding closures:

A closure (short for 'lexical closure') is so named because it 'closes
over' the free variables in its function body using the scope in which
it's defined, rather than the scope in which it's used.  All the
variable references have to refer to some variable for the code to
work.  Note that the *variables* are being captured, not the values
they hold at the time the closure is created.  Since there is a single
'i' variable and a single 'clientnum' variable created *per invocation
of blockCountCallBack*, all of the closures created by each invocation
of blockCountCallBack will refer to the *same* two variables.  This is
often what you want, but it certainly isn't what you want in this

Regarding asynchronous callbacks:

You have a loop in which you are setting a timeout per block in
blockcount.  The loop has no blocking functions, so it's going to take
very little time per iteration.  You use the same 500ms timeout for
each block, which means '500ms from the time at which setTimeout is
called'.  So, you are essentially shifting the entire loop execution
500ms into the future, but *not* introducing 500ms of delay between
the resulting API calls.  For that, you would have to do a delay of i
* 500ms.

Also, note that the function to be invoked by the timeout does not
actually invoke addBlockToMessage itself.  It just passes it to
getBlockHash on clients[clientnum] (where clientnum holds the value of
the *single* clientnum variable at the time the callback occurred...
with a low enough delay or a sufficiently slow loop, this could be
interleaved with loop execution... but since there's only one thread
of execution, the events will just queue up until your loop is
finished.).  If getBlockHash never calls addBlockToMessage, you'll
never see addBlockToMessage's debug output.

Regarding the clientnum variable:

It holds the value 'undefined' until the first execution of the loop
reaches the 'var clientnum = 0' line, immediately after which it holds
the value 0.
So, it's unclear from what you pasted how big clients.length is, but
until i == clients.length clientnum will have the value 0. After that,
it will increment per loop until it resets to 0 at 2 * clients.length.
It seems unlikely that you intend for all the first set of callbacks
to go to client 0 and sometime later start round-robining them.
But, due to the fact that there's only one 'clientnum' variable and
you're likely to have i be well past clients.length by the time 500ms
have elapsed, they're all either going to be assigned whatever the
final value of clientnum ends up being.

> And here is the addBlockToMessage function that should be getting called,
> but never does.
> //Adds blockhashes to the blocks array
> //When the array reaches it's max size (currently 7KB), it creates an SQS
> message and sends it off.
> //It then clears the blocks[] so the whole process can start over again
> function addBlockToMessage(err, blockhash){
>     //This error handling isn't likely to work, we need somehow verify that
> we are going to preserve the number itself.
>     //This is WAY too fragile!!!
>     if(err){
>         console.log(err);
>         if(err.code ==="ECONNREFUSED"){
>             console.log("link appears to be down.  Sleeping for 5 minutes");
>             var blockid = blockhash;
>             setTimeout(function(){
>                 fetchBlockID(blockid);
>                 },FIVEMINUTES);
>             return;
>         }
>     }
>     //We should batch these into a couple hundred, just check the byte
> length and not exceed 7k
>     blocks.push(blockhash);
>     var msgContent = JSON.stringify(blocks);
>     var msgLength = msgContent.length;
>     if(msgLength >= 7000){
>         console.log("Sending: ",msgContent);
>         //We've reached the size limit
>         //Now we setup and send the SQS message
>         AWS.Request.send(sqs.SendMessage(qURL, msgContent));
>         //Finally clear blocks
>         blocks = [];
>     }
> }
> As you can see there should be plenty of debug log output, but all this
> thing is doing is iterating.
> Any thoughts?

You would also see a lack of debug logging if addBlockToMessage was
called successfully, but you never reached a message size of 7000.
But it seems from other messages you've sent that addBlockToMessage
just wasn't getting called.

More information about the PLUG mailing list