Writing tests and learning promises in node.js (part 2)

(In which I explore how errors are thrown and caught from within promises.)

Following up on my last post documenting work fixing up my bulkdoc appender code, for the paste few days I’ve worked on my couch_set_state code. The purpose of this package is to facilitate using CouchDB as a way to save state. I find this incredibly convenient for tracking jobs across multiple machines. I just set up my state tracking database to replicate between all my computers, and then can coordinate work between them by having code check the local CouchDB for state—things like whether a chunk of data has been processed, whether figures have been rendered, and so on. This package has utilities to set state, and a companion package couch_check_state facilitates checking state.

One of the things I wrote for the bulkdocs package was the ability to generate database conflicts. One of the design features of CouchDB is that it refuses to save a document unless the saver is updating the latest version of the document. The way my libraries work (both the bulkdocs appender and this state setting code) they first get the latest version of the document from the database, then they make their changes, then they save the updated document to the database. The problem is that if many jobs are running at once it is always possible that a race condition will arise where two processes are trying to update the same document at the same time. I actually hit this in practice last week, which is why I decided to write test code to trigger this issue.

For the bulkdoc appender code, I wrote a simple hack to keep retrying the update or append until it succeeded. For this state setting package, I instead decided to explore how errors are handled in promises. Because I figured out some things, and because I often forget stuff unless I write it up, I’m writing this blog post right on the heels of my last one.

The purpose of the set state code

My “set state” conventions were designed around road traffic data collection devices. Each device has a unique id, and collects data for many years. Typically, historical data is processed on a year basis, with several steps that have to happen each year. I needed to keep track of which data processing steps had been completed for each detector for each year. I wanted to hit CouchDB and be able to answer questions like “What is the truck imputation state for detector X for year Y?” Thus the state document looks like the following:

{"_id": "801245",
  ...
 "2007": {
     "vdsimputed": "done",
     "truckimputed": "2013-04-06T04:45:11.832Z finish",
     "paired_wim": null,
     "vdsdata": "1",
     "rawdata": "1",
     "vdsraw_chain_lengths": [2,2,2,2,2],
     "vdsraw_max_iterations": 0,
     "occupancy_averaged": 1,
     "truckimputation_chain_lengths": [
         145,
         147,
         144,
         139,
         143
     ],
     "truckimputation_max_iterations": 0
 },
 "2008": {
     "vdsimputed": "todo",
   ...

I don’t try to be too fastidious about what states get set and used. If a program needs to set or check a state, it does so. Also, over time I decided that year can be optional, because sometimes it doesn’t make sense to have a year field limiting a state. For example, a state can be the geographic coordinates of a detector.

According to the code coverage reports generated by tap (via Istanbul), my tests cover most of my code. The one area that tends to be missing is the error handling bits—the code that handles bad requests to CouchDB and so on. For the first few years of using this code, I never had a problem. But a few weeks ago I put a bunch of set state calls in a loop that I forgot to throttle, and I hit strange document conflict errors that I couldn’t seem to trap. One simple solution is to just switch to using the bulk docs API to batch together all the calls into one call. But that would be like hiding my head in the sand rather than dealing with the problem now.

Generating a race condition

So the first task is to generate a race condition that causes CouchDB to throw a document conflict error. It turns out this is very easy to do, given how JavaScript handles asynchronous calls. In pseudo-code, my set state function does the following:

GET the specified document id from CouchDB (if it exists)
if (no document){
   create a new document with the requested state
}else{
   update the existing document with the requested state
}
PUT the document into CouchDB

This is the only way to modify an existing document. CouchDB requires that any changes to an existing document also contain the current version of the document’s _rev tag. The first GET not only gets the document, but just as importantly, gets the current revision number. The document is then modified as needed, and then the document is PUT to CouchDB. If the document is a new one, the missing _rev field is fine.

Given this logic, if there are two or more requests in the same JavaScript event loop to set state on a specific document id, CouchDB will throw a conflict error for all but one of those set state calls. The first of the competing queries to PUT an updated document with the current _rev tag will win; all others will have an out-of-date _rev value and so will not be accepted. For example, if there are two calls to set state on document id 12345:

EVENT LOOP 1

  set_state({'doc':12345,'year':2017,'state':'mega','value':'unproductive', ... couch details ... })
    <set up GET for document '12345'>

  set_state({'doc':12345,'year':2017,'state':'mega','value':'counter-productive', ... couch details ... })
    <set up GET for document '12345'>

EVENT LOOP 2

  {'unproductive' setter}
    desired document: {2017 : {'mega':'unproductive'}}
    <got document 123456 with revision '1_123456'>
    <set up PUT for document '12345', revision '1_123456',

  {'counter-productive' setter}
    desired document: {2017 : {'mega':'counter-productive'}}
    <got document 123456 with revision '1_123456'>
    <set up PUT for document '12345', revision '1_123456',

EVENT LOOP 3

  {'unproductive' setter}
    CouchDB response: Status 201, {'ok':true,'id':123456,'rev':'2_2564465'}

  {'counter-productive' setter}
    CouchDB response: Status 409, {error:'conflict', reason:'Document update conflict.'}

In this example, the first pass through the code fires off two calls to set_state. The next go around on the event loop will hit CouchDB and GET the current document. Then in the last cycle, the first PUTs will get there first and will increment the revision. Every other PUT for the same document will therefore have the wrong revision, and CouchDB will reject it. In a way this is a great plan…CouchDB doesn’t need to know anything about the document being stored. All it knows is that because the revision is wrong, the request is operating on stale information and needs to be updated and done again.

In my above example, I’ve set the exact same state (“mega”) for the exact same year (2017) in the target document. This is the worst case for handling the error, as I can’t think of any way for library code to be able to decide on a winner. In order to “handle” this type of conflict error, my state setting logic has to recognize in this case that this is a true conflict, in which two requests are trying to set the exact same state to different values. Other cases with different years and different state keys still require some tricksy logic, but at least they can be sorted automatically if I choose to do that.

The code for triggering this error in my test is super simple:

const setter = require('../couch_set_state')
...
const docids = [1]        // same docid leads to conflict
const years = [2017,2017] // same year leads to conflict
... config.couchdb = couchdb connection options ...
years.forEach( y => {
   docids.forEach (id => {
      const task = Object.assign( {'doc':id
                                   ,'year':y
                                   ,'state':'mega'
                                   ,'value':'productive'}
                                 ,config.couchdb)
      let passed_job = 0
      const yearly_job = setter(newtask)
            .then( results =>{ // (this should only hit once)
                // for job that passes, expect results is okay
                passed_job++
                tt.is(passed_job,1) // one winner expected
                tt.is(results.status,201)
                tt.ok(results)
                tt.ok(results.body)
                tt.ok(results.body.ok)
                tt.ok(results.body.id)
                tt.ok(results.body.rev)
                return null
            })
            .catch(e =>{
                tt.is(e.status,409)
                tt.ok(e.response)
                tt.ok(e.response.body)
                tt.is(e.response.body.reason,'Document update conflict.')
                // expect to fail until I fix my code, but call fail anyway
                tt.fail('should not have conflicts')
                throw e
                return null
            })
      jobs.push(yearly_job)
      return null
   })
   return null
})
return  Promise.all(jobs) // wait for the two jobs to finish
        .then( results =>{
            tt.pass('should not hit any conflicts.')
            // all done with this test
        })
        .catch(e=>{
            tt.is(e.status,409)
            tt.ok(e.response)
            tt.ok(e.response.body)
            tt.is(e.response.body.reason,'Document update conflict.')
            // expect to fail until I fix my code, but call fail anyway
            tt.fail('set docs loop crashed with a document conflict')
            tt.end()
        })

Promises and thrown errors

One of the interesting things to me about switching to promises is that thrown errors can be handled. In the past I’ve always expected that a throw from an asynchronous call is pretty much going to kill off everything. However in this case the thrown errors can be handled in the catch statements. This is then how I will write my conflict handler. If an error occurs and if it is a conflict, then I’ll try to handle it and resubmit the PUT. If it isn’t or if the conflict can’t be resolved, then I’ll throw a new error.

Resolving the conflict in my code

In my use cases, there should never be a case in which I try to set the same state key for the same year to two different things. However, regardless of whether I expect that case or not, if it happens then I need to throw and error. In all other cases, I want the code to compare the newly revised document to the previously saved version, decide whether or not this is an “unresolvable conflict” case, and then update the document if it isn’t. There are a few tricky edge cases and my code can probably be refactored a bit, but I settled on a recursive loop. The first pass through the loop stores a copy of the original document’s original year and state, or undefined if it is a new document. Then every time a conflict is hit, re-get the new document, make sure that the state we’re trying to set hasn’t been modified since the original document was retrieved (if so that is a conflict we can’t fix), and then retry setting the state. The recursion maxes out at 10 iterations, or when the document is successfully updated.

function make_conflict_handler(desired_state,getter,putter){
    let looplimit = 10
    let update_safe
    const year = desired_state.year
    const state = desired_state.state
    const value = desired_state.value
    let old_doc = {}
    let conflict_err
    const conflict_handler = err => {
        conflict_err = err
        // compare old doc with the new doc in results
        // focusing on the key we're trying to update in desired_state
        return getter()
            .then( doc =>{
                if(! update_safe ){
                    old_doc = set_old_doc(year,state,doc)
                    update_safe = year_test(year,state,old_doc,conflict_err)
                }else{
                    if(!update_safe(doc)){
                        //console.log('not safe to update')
                        throw conflict_err
                    }
                }
                // if still here, didn't throw
                // if didn't throw, either first pass, or update safe
                return putter(doc)
                    .catch( err=> {
                        if(looplimit-- > 0 &&
                           err.status !== undefined &&
                           err.status === 409) {
                            return conflict_handler(err)
                        }else{
                            throw err
                        }
                    })
            })
    }
    return conflict_handler
}

In the main loop I set up the getter and putter to already contain the CouchDB details, so the recursive loop is triggered by a call to the conflict handler generated by the above function:

    ... main function ...
    const query = cdb+'/'+db+'/'+id
    const put_job = make_putter(query,desired_state)
    const get_job = make_getter(query)
    // now set up the recursive get/put/retry chain of commands
    const conflict_handler =
          make_conflict_handler(
              desired_state
              ,get_job
              ,put_job
          )
    return conflict_handler()

This function works fine. However I learned some things about Promises when trying to test it.

New learnings about Promise.all()

The first thing I learned is that Promise.all doesn’t do what I thought it did. From reading the docs, I knew that if any of the list of promises passed to Promise.all rejects or throws, then the Promise.all will exit to its catch handler or throw and error up the chain. Stupidly, I didn’t think about what this means. But it is easier to show the problem than it is to describe it.

First, here is how I set up a set of jobs that I knew would generate an unresolvable conflict:

const tap = require('tap')
...
function testing (t){
    return t.test('unresolvable conflicts', (tt) =>{
        // two unique document ids
        const docids = [1,2].map( d => { return 'superspecial_'+d })
        // two identical years
        const years = [1,1].map( y =>{return 2010 + y} )
        const jobs = []
        years.forEach( y =>{
            docids.forEach( id =>{
                const newtask = Object.assign(
                    {'doc':id,'year':y,'state':'mega','value':'unproductive'}
                    ,config.couchdb)
                const yearly_job = setter(newtask)
                    .then( results =>{
                        // expect results is okay across all docs
                        tt.is(results.status,201)
                        tt.ok(results.body.ok)
                        tt.ok(results.body.id)
                        tt.ok(results.body.rev)
                        return null
                    })
                    .catch(e =>{
                        tt.is(e.status,409)
                        tt.is(e.response.body.reason,'Document update conflict.')
                        tt.pass('should have conflicts')
                        // pass the error up the chain
                        throw e
                    })
                jobs.push(yearly_job)
                return null
            })
            return null
        })
        return Promise.all(jobs)
            .then( results =>{
                tt.fail('should have caught a conflict error')
                return null
            })
            .catch(e=>{
                tt.is(e.status,409)
                tt.is(e.response.body.reason,'Document update conflict.')
                tt.pass('did crashed with a document conflict')
                tt.end()
            })
    }).catch(tap.threw)
}

So that test should spawn 4 jobs, two each for two unique ids. For all jobs the state “mega” is supposed to be assigned “unproductive”. I want this case to fail in the second situation because even though the state values are the same in both cases (both “unproductive”), in the real world the calling code should be surprised by this and should be alerted that there was a conflict. When the state is set successfully, the lower level job should step through the then routine and test that the results are as expected. When the state hits the conflict case, the code will step through the catch routine and will then pass the error up the chain by throwing the error again.

At the higher level, the jobs are collected and wrapped up with Promise.all(). I expect that this will fail and will trigger the catch code, so if it hits the then I set a test failure. Inside the Promise.all(jobs).catch() I check that the error is what I expect, then call tt.pass and end the test.

However when I run this, it fails. But not for the reasons I was expecting.

james@emma couch_set_state[blogpostwork]$ ./node_modules/.bin/tap -R list  test/test_handle_race.js

  ․ test/test_handle_race.js test setting state unresolvable conflicts should be equal: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts expect truthy value: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts expect truthy value: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts expect truthy value: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts should be equal: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts expect truthy value: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts expect truthy value: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts expect truthy value: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts should be equal: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts should be equal: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts should have conflicts: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts should be equal: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts should be equal: NaNms
  ․ test/test_handle_race.js test setting state unresolvable conflicts did crashed with a document conflict: NaNms
Error: test after end() was called
    at setter.then.catch.e (/home/james/repos/jem/couchdb_utils/couch_set_state/test/test_handle_race.js:342:28)
    at process._tickDomainCallback (internal/process/next_tick.js:135:7)
{ name: 'unresolvable conflicts',
  cb: [Function],
  ...
  ... repeated lots of times ...
  ...
  1) test/test_handle_race.js

  14 passing (345.796ms)
  1 failing

  1) test/test_handle_race.js:
     test/test_handle_race.js

So there we are, hitting the “did crashed with a document conflict” test, then ending the test, then I get more tests?? And the test (line 342 in the output) are for the inner loop catch tests—the test that the status is 409. I tried all sorts of things trying to figure this out, and then I realized that my mistake was throwing from within the inner catch.

What happened was this:

spawn couch job #1 with then, catch
spawn couch job #2 with then, catch
spawn couch job #3 with then, catch
spawn couch job #4 with then, catch

couch job #1 success
couch job #2 conflict -> trigger catch, throw

couch job #3 success (probably the right order)

Promise.all().catch -> tests, then test.end() called

couch job #4 conflict -> trigger catch, fail on tests after end

In other words, just because Promise.all() aborted its processing, it does not abort processing of the other jobs. They still happen no matter what, short of completely killing the program.

This has major implications for using Promise.all() to wait for database jobs to finish. All of the jobs will finish, but if any of them error out or throw, then there is no way for the Promise.all() .then() .catch() sequence to know anything about the successes. In fact, because the catch only gets the error, if any of the jobs throw, then I lose all knowledge of the successes, and only get information on one of the failures.

In Nolan Lawson’s excellent post We have a problem with promises, he has an example of using Promise.all() with pouchdb as follows:

db.allDocs({include_docs: true}).then(function (result) {
  return Promise.all(result.rows.map(function (row) {
    return db.remove(row.doc);
  }));
}).then(function (arrayOfResults) {
  // All docs have really been removed() now!
});

What he missed in this example, and what I learned with this exercise, is that if any of those “remove” statements fail, then you don’t hit the “arrayOfResults” part. Instead you get:

db.allDocs({include_docs: true}).then(function (result) {
  return Promise.all(result.rows.map(function (row) {
    return db.remove(row.doc); // what if something fails?
  }));
}).then(function (arrayOfResults) {
  // All docs have really been removed() now!
}).catch(function (error) {
  // Promise.all aborted becaue one db.remove failed with "error"
  // but maybe all the others succeeded?  maybe none succeeded?
  // no clue, now way to find out here
  throw ('Oh bother!')
});

What I learned is that Promise().catch() is not a one way ticket to Failsville. Instead, if you return a value from catch, then all is well. My mistake in my code is that I was throwing from the inner catch statement. What I really should do is return a value that says there was a conflict, as follows:

const yearly_job = setter(newtask)
    .then( results =>{
        // expect results is okay across all docs
        tt.is(results.status,201)
        tt.ok(results.body.ok)
        tt.ok(results.body.id)
        tt.ok(results.body.rev)
        return results.body
    })
      .catch(e =>{
        tt.is(e.status,409)
        tt.is(e.response.body.reason,'Document update conflict.')
        tt.pass('should have conflicts')
        // pass the error up the "success" side of the chain
        return Object.assign({'id':newtask.doc},e.response.body)
    })

Now the then branch returns the successful response from CouchDB, and the catch branch returns the conflict message from CouchDB along with the id of the document (which is not included in CouchDB’s error message).

Then the higher level Promise.all handlers look like

return Promise.all(jobs)
    .then( results =>{
        let passes = 0
        let failures = 0
        results.map( result =>{
            if(result.rev !== undefined &&
               result.ok ){
                passes++
            }
            if(result.error === 'conflict' &&
               result.reason === 'Document update conflict.'){
                failures++
            }
            return null
        })
        tt.equal(passes,2,'got two successful state set cases')
        tt.equal(failures,2,'got two failed state set cases')
        tt.pass('no longer bailing out because that is horrible.')
        tt.end()
        return null
    })
    .catch(e=>{
        tt.is(e.status,409)
        tt.is(e.response.body.reason,'Document update conflict.')
        tt.fail('should not be catching in promise.all')
    })

In this version, I never expect to land in the catch handler, and I also expect that the results sent to the then handler will contain two successful cases and two failures.

And the test succeeds:

james@emma couch_set_state[blogpostwork]$ ./node_modules/.bin/tap  test/test_handle_race.js
test/test_handle_race.js ............................ 17/17
total ............................................... 17/17

  17 passing (318.169ms)

  ok

So a stern warning to my future self. If you have a bunch of database actions wrapped in Promises, handle all expected errors right at the job. If it fails in an expected way, return that. Only throw (or pass along a Promise.reject()) if it is a bad unknown error and you want everything to die.

To update the example from the PouchDB blog post, I would do this:

db.allDocs({include_docs: true}).then(function (result) {
  return Promise.all(result.rows.map(function (row) {
    return db.remove(row.doc)
                .catch( function (error) {
                   // maybe the document doesn't exist
                   // maybe there is a conflict and the _rev isn't right
                   if(error.status === 404 || error.status === 409){
                      return Object.assign(error.body,{id:row.doc.id})
                   }else{
                      // some other problem
                      throw error
                   }
                })
  }));
}).then(function (arrayOfResults) {
  // we can check array of results to see if all docs have really been
  // removed() and we can re-remove those with conflicts, and ignore
  // errors for documents that are already gone (404 not found)
}).catch(function (error) {
  // Promise.all aborted becaue one db.remove failed with an "error"
  // that is neither 404 not found nor 409 conflict.  Probably should
  // pass the error up and attempt to crash now.
  throw (error)
});

A reminder that asynchronous processes follow a different drummer

The other thing I learned, or rather, was reminded of, is that asynchronous processes follow their own timings. When you call out to a database to do something, it will not run the jobs in an orderly fashion, and it will not return work in the order it was submitted. It will do its own thing.

I remembered this when setting up the test for the timeout code. The loop set up twelve jobs, and I expected two to fail. In practice, the 12 CouchDB jobs did not fit neatly into my loops, but instead bled out the edges, such that some documents had their get/put loops done after other documents, and so they succeeded without hitting a conflict error.

The test loop looks similar to before, with the Promise.all() being slightly different:

    return t.test('test timeout after 10 tries to resolve conflicts', (tt) =>{
        const docids = [1].map( d => { return 'superspecial_'+d })
        const states = ['Nicaragua','Cuba','Venezuela']
        const years = [
            1,2,3,4
        ].map( y =>{return 2010 + y} )
        const jobs = []
        years.forEach( y => {
            docids.forEach( id =>{
                states.forEach ( state => {
                    ...
                    const job = setter(newtask)
                       .then(...) // as before
                       .catch(...)// as before
                    jobs.push(job)
                })
            })
        })
        // set up 12 jobs (4 years times 3 states times 1 id)
        return Promise.all(jobs)
            .then( results =>{
                console.log(results.length)
                tt.is(results.length,years.length*states.length*docids.length
                      ,'got expected size of output from promise.all')

                let passes = 0
                let failures = 0
                results.map( result =>{
                    if(result.rev !== undefined &&
                       result.ok ){
                        passes++
                    }
                    if(result.error === 'conflict' &&
                       result.reason === 'Document update conflict.'){
                        failures++
                    }
                    return null
                })
                tt.equal(passes,10,'got 10 successful state set cases')
                tt.equal(failures,2 ,'got expected number of failed state set cases')
                tt.end()
                // all done with this test
            })
            .catch(e=>{
                tt.fail('Oops.  should not have crashed with a document conflict')
            })

The test fails every time, with either all 12 cases succeeding, or just one failing. For example:

james@emma couch_set_state[blogpostwork]$ ./node_modules/.bin/tap  test/test_handle_race.js
test/test_handle_race.js ............12
test/test_handle_race.js ............................ 48/50
  test setting state > test timeout after 10 tries to resolve conflicts
  not ok got 10 successful state set cases
    +++ found
    --- wanted
    -10
    +11
    compare: ===
    at:
      line: 382
      column: 20
      file: test/test_handle_race.js
      type: global
      function: Promise.all.then.results
    stack: |
      Promise.all.then.results (test/test_handle_race.js:382:20)
    source: |
      tt.equal(passes,10,'got 10 successful state set cases')

  test setting state > test timeout after 10 tries to resolve conflicts
  not ok got expected number of failed state set cases
    +++ found
    --- wanted
    -2
    +1
    compare: ===
    at:
      line: 383
      column: 20
      file: test/test_handle_race.js
      type: global
      function: Promise.all.then.results
    stack: |
      Promise.all.then.results (test/test_handle_race.js:383:20)
    source: |
      tt.equal(failures,2 ,'got expected number of failed state set cases')

total ............................................... 48/50


  48 passing (566.069ms)
  2 failing

I instrumented the set state code, and it demonstrates clearly what is going on:

safe to update superspecial_1 3-7fccd3635a18617f7913805e9d463fcc  to  { year: 2012, state: 'Venezuela', value: 'vacay' }
successful put for  { year: 2013, state: 'Venezuela', value: 'vacay' }
safe to update superspecial_1 4-af97b020753170f483cb0e52d769e047  to  { year: 2014, state: 'Nicaragua', value: 'vacay' }
safe to update superspecial_1 4-af97b020753170f483cb0e52d769e047  to  { year: 2013, state: 'Cuba', value: 'vacay' }
safe to update superspecial_1 4-af97b020753170f483cb0e52d769e047  to  { year: 2013, state: 'Nicaragua', value: 'vacay' }
safe to update superspecial_1 4-af97b020753170f483cb0e52d769e047  to  { year: 2012, state: 'Nicaragua', value: 'vacay' }
safe to update superspecial_1 4-af97b020753170f483cb0e52d769e047  to  { year: 2012, state: 'Venezuela', value: 'vacay' }
safe to update superspecial_1 4-af97b020753170f483cb0e52d769e047  to  { year: 2014, state: 'Cuba', value: 'vacay' }
safe to update superspecial_1 4-af97b020753170f483cb0e52d769e047  to  { year: 2011, state: 'Venezuela', value: 'vacay' }
safe to update superspecial_1 4-af97b020753170f483cb0e52d769e047  to  { year: 2014, state: 'Venezuela', value: 'vacay' }
successful put for  { year: 2013, state: 'Cuba', value: 'vacay' }
safe to update superspecial_1 5-1383eea7c1ffdf37fea0c78e3b248e7d  to  { year: 2014, state: 'Nicaragua', value: 'vacay' }
safe to update superspecial_1 5-1383eea7c1ffdf37fea0c78e3b248e7d  to  { year: 2013, state: 'Nicaragua', value: 'vacay' }
successful put for  { year: 2014, state: 'Nicaragua', value: 'vacay' }
safe to update superspecial_1 6-4599771ae9ab462c035d6f32089788b1  to  { year: 2012, state: 'Nicaragua', value: 'vacay' }
safe to update superspecial_1 6-4599771ae9ab462c035d6f32089788b1  to  { year: 2012, state: 'Venezuela', value: 'vacay' }
safe to update superspecial_1 6-4599771ae9ab462c035d6f32089788b1  to  { year: 2014, state: 'Cuba', value: 'vacay' }
safe to update superspecial_1 6-4599771ae9ab462c035d6f32089788b1  to  { year: 2014, state: 'Venezuela', value: 'vacay' }
safe to update superspecial_1 6-4599771ae9ab462c035d6f32089788b1  to  { year: 2011, state: 'Venezuela', value: 'vacay' }
safe to update superspecial_1 6-4599771ae9ab462c035d6f32089788b1  to  { year: 2013, state: 'Nicaragua', value: 'vacay' }
successful put for  { year: 2012, state: 'Venezuela', value: 'vacay' }
safe to update superspecial_1 7-69d331e55d89707279b156f403e75df3  to  { year: 2012, state: 'Nicaragua', value: 'vacay' }

In the first few iterations, I get the expected ten “safe to update” messages, then nine, then eight, etc, interspersed with a single “successful put” message. But then after the 5th update, I only see two “safe to update” messages, and then another “successful put” message. That means one of the get/put jobs (actually, Nicaragua, 2014) executed before 5 of the other 6 get/put jobs had executed their “get” statements. It had the latest document revision, and therefore could save its value to CouchDB without hitting a conflict. That’s why the subsequent “safe to update” messages have a new incremented revision number.

The lesson (that I already knew but keep forgetting) is that asynchronous processes really are outside of the logic of the node program that is triggering them.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s