                          try
                              lock = misc.from_json(output.stdout)
                              if lock.expire > misc.walltime()
-                                 cb("project at #{user} is currently locked")
+                                 mesg = "create_lock: project at #{user} is currently locked"
+                                 winston.debug(mesg)
+                                 cb(mesg)
                                  return
                          catch e
                              # corrupt lock file -- we take over

    winston.debug("adding #{opts.project_id} to queue")
    snapshot_queue.push({project_id:opts.project_id, cbs:[opts.cb]})

repository_is_corrupt = false
monitor_snapshot_queue = () ->
    if snapshot_queue.length > 0

        if repository_is_corrupt
            while snapshot_queue.length > 0
                {project_id, cbs} = snapshot_queue.shift()
                for cb in cbs
                    cb?("the repository is totally corrupt")
            return

        user = undefined
        winston.debug("snapshot_queue = #{misc.to_json(snapshot_queue)}")
        {project_id, cbs} = snapshot_queue.shift()

        location    = undefined
        user        = undefined
        timestamp   = undefined
        size_before = undefined
        size_after  = undefined
        repo_id     = undefined
        bup_active  = undefined
        retry_later = false
        nothing_to_do = false
        rollback_info = undefined
        rollback_file = undefined
        modified_files = undefined
        async.series([
            (cb) ->
                winston.debug("snapshot: checking if disabled for #{project_id}")
                database.select_one
                    table   : 'projects'
                    where   : {project_id: project_id}
                    columns : ['snapshots_disabled']
                    objectify : false
                    cb      : (err, result) ->
                        if err
                            cb(err)
                        else
                            if result[0]
                                cb("snapshots disabled for #{project_id}t")
                            else
                                cb()

            (cb) ->
                winston.debug("snapshot: getting active path")
                active_path (err, path) ->
                    if err
                        cb(err)
                    else
                        repo_id = path.repo_id
                        bup_active = path.active_path
                        rollback_file = "#{bup_active}/rollback"
                        cb()

            # compute disk usage before save
            (cb) ->
                winston.debug("snapshot: compute disk usage before save")
                misc_node.disk_usage bup_active, (err, usage) ->
                    winston.debug("usage: #{err}, #{usage} bytes")
                    size_before = usage
                    cb(err)

            # check for a leftover rollback file; this will be left around when the
            # server is killed while making a backup.
            (cb) ->
                fs.exists rollback_file, (exists) ->
                    winston.debug("found rollback file")
                    if exists
                        fs.readFile rollback_file, (err, data) ->
                            if err
                                cb(err)
                            else
                                s = data.toString()
                                try
                                    rollback_info = misc.from_json(s)
                                    winston.debug("rollback info: '#{s}'")
                                catch
                                    # Something went wrong parsing the rollback JSON file; maybe it is corrupt
                                    # or empty.  This would be a good place to take more dramatic measures,
                                    # once they are implemented.
                                    winston.debug("rollback file *corrupt* (not using); content='#{s}'")
                                    rollback_info = undefined

                                if rollback_info?
                                    rollback_last_save
                                        rollback_info : rollback_info
                                        cb            : (err) ->
                                            if err
                                                cb(err)
                                            else
                                                fs.unlink(rollback_file, cb)
                                else
                                    cb()
                    else
                        cb()

            (cb) ->
                get_rollback_info
                    bup_dir : bup_active
                    cb      : (err, info) ->
                        rollback_info = info
                        cb(err)

            # get deployed location of project (which can change at any time!)
            (cb) ->
                database.get_project_location
                    project_id : project_id
                    cb         : (err, _location) ->
                        if err
                            cb(err)
                        else
                            if not _location or not _location.username?
                                cb("can't snapshot #{project_id} since it is not deployed")
                                return
                            location = _location
                            user = "#{location.username}@#{location.host}"
                            # TODO: support location.port != 22 and location.path != '.'   !!?
                            cb()

            # get a lock on the deployed project
            (cb) ->
                winston.debug("Trying to lock #{project_id} for snapshotting.")
                create_lock
                    location : location
                    cb       : (err) ->
                        if err
                            retry_later = true
                            winston.debug("Couldn't lock #{project_id}, so put back in the queue to try again later (in 30 seconds)")
                            f = () ->
                                for c in cbs
                                    snapshot_project(project_id:project_id, cb:c)
                            setTimeout(f, 30000)
                        cb(err)

            # create index
            (cb) ->
                t = misc.walltime()
                bup
                    args : ['on', user, 'index', '.']
                    bup_dir : bup_active
                    cb   : (err) ->
                        winston.debug("time to index #{project_id}: #{misc.walltime(t)} s")
                        cb(err)

            # List the interesting modified files.
            # This only makes sense because we just made the index above successfully.
            # Note that "modified" is global to *all* snap servers, so this is actually
            # a really sensible thing to do.  And if one snap server makes a snapshot,
            # then no other snapshot server will make exactly the same snapshot (by a different name),
            # which is what we want, since we will (eventually-when-i-implement-it!)
            # get redundancy by rsyncing them around.
            (cb) ->
                misc_node.execute_code
                    command : "/usr/bin/bup on #{user} index -m . 2>&1 | grep -v ^./.forever |grep -v ^./.sagemathcloud|grep -v '^./$'"
                    timeout : 30  # should be very fast no matter what.
                    bash    : true
                    env     : {BUP_DIR : bup_active}
                    err_on_exit : false  # if a grep along the way above is empty -- i.e., no file changes, then get a 1 exit code.  STUPID, but yep.
                    cb      : (err, output) ->
                        if err
                            winston.debug("SERIOUS BUG issue: error determining number of modified files for #{project_id}: #{err}")
                            cb(err)
                        else
                            modified_files = (x.slice(2) for x in output.stdout.trim().split('\n'))
                            modified_files = (x for x in modified_files when x != "")
                            n = modified_files.length
                            winston.debug("#{n} modified files for #{project_id}")
                            winston.debug("modified files = #{misc.trunc(misc.to_json(modified_files),512)}")
                            if n == 0
                                nothing_to_do = true
                                _last_snapshot_cache[project_id] = misc.walltime() # don't try again to snapshot this project for a few minutes (otherwise we would index the whole thing every few seconds!)
                                remove_lock
                                    location : location
                                    cb       : (err) -> cb(true)
                            else
                                cb()

            # write rollback file
            (cb) ->
                fs.writeFile rollback_file, misc.to_json(rollback_info), cb

            # save
            (cb) ->
                winston.debug("doing the actual save...")
                t = misc.walltime()
                d = Math.ceil(misc.walltime())
                bup
                    args : ['on', user, 'save', '-d', d, '--strip', '-q', '-n', 'master', '.']
                    bup_dir : bup_active
                    cb   : (err) ->
                        winston.debug("time to save snapshot of #{project_id}: #{misc.walltime(t)} s")

                        # If bup is killed during save, then this doesn't get removed, and on use
                        # we rollback as specified.
                        fs.unlink "#{bup_active}/rollback"

                        if not err
                            # used below when creating database entry
                            timestamp = moment(new Date(d*1000)).format('YYYY-MM-DD-HHmmss')
                        # No matter what happens, we need to remove the lock we just made *now*.
                        remove_lock
                            location : location
                            cb       : (lock_err) ->
                                if lock_err
                                    winston.debug("non fatal error removing snapshot lock (#{project_id}) -- #{lock_err}")
                                if err
                                    rollback_last_save
                                        rollback_info:rollback_info
                                        cb : (rb_err) ->
                                            cb(err)
                                else
                                    cb(err) # err is the outer err from saving

            # Do a "bup ls", which causes the cache to be updated (so a user doesn't have to wait several seconds the
            # first time they do a view on a snapshot).  Also, if this fails for some reason, we do *NOT* want to
            # ever record this as a successful snapshot in the database.
            (cb) ->
                t = misc.walltime()
                bup
                    args    : ['ls', "master/#{timestamp}"]
                    bup_dir : bup_active
                    cb      : (err) ->
                        winston.debug("time to get ls of new snapshot #{timestamp}: #{misc.walltime(t)} s")
                        cb(err)

            # Compute disk usage after snapshot -- how much disk space was used by making this snapshot
            # (The main reason for doing this is to protect against projects that have random data
            # files in them -- we can refuse to snapshot after a certain total amount of usage.)
            (cb) ->
                misc_node.disk_usage bup_active, (err, usage) ->
                    size_after = usage
                    # Also, save total size of bup archive to global variable, so it can
                    # be reported on next update the snap_servers table.
                    size_of_bup_archive = size_after
                    cb(err)

            # record (in db) that we successfully made a snapshot, unless snapshot was too big.
            (cb) ->
                size = size_after - size_before
                winston.debug("Snapshot of #{project_id}: increased archive by #{size} bytes")
                if size > MAX_SNAPSHOT_SIZE
                    err = "*** Snapshot size of #{project_id} exceeds max snapshot usage size of #{MAX_SNAPSHOT_SIZE}, so we are removing it, and turned off snapshots of this project in the database."
                    winston.debug(err)

                    database.update  # fire and forget this
                        table : "projects"
                        set   : {"snapshots_disabled":true}
                        where : {project_id : project_id}

                    rollback_last_save
                        rollback_info : rollback_info
                        cb : (rb_err) ->
                            cb(err)
                    return

                t = misc.walltime()
                _last_snapshot_cache[project_id] = t
                database.update
                    table : 'snap_commits'
                    set   : {size: size, repo_id:repo_id, modified_files:modified_files}
                    json  : ['modified_files']
                    where :
                        server_id  : server_id
                        project_id : project_id
                        timestamp  : timestamp
                    cb    : (err) ->
                        winston.debug("time to record commit to database: #{misc.walltime(t)}")
                        cb()

                # Also add row to table for each modified file.  There could be a 50,000 files though,
                # so this is slow, so we don't block on it.  TODO: do this in one transaction someday.
                f = (filename, cb) ->
                    database.update
                        table : 'snap_modified_files'
                        set   : {dummy: true}
                        where :
                            project_id : project_id
                            filename   : filename
                            timestamp : timestamp
                        cb : cb
                t = misc.walltime()
                async.map modified_files, f, (err) ->
                    winston.debug("finished recording snap_modified_files for project #{project_id}, time = #{misc.walltime(t)}")

        ], (err) ->
            # wait 3 seconds, to ensure uniqueness of time stamp, not be too aggressive checking locks, etc.
            setTimeout(monitor_snapshot_queue, 3000)
            if nothing_to_do
                err = undefined
            if not retry_later
                for cb in cbs
                    cb?(err)
        )
    else
        # check again soon
        setTimeout(monitor_snapshot_queue, 3000)

# snapshot all projects in the given input array, and call opts.cb on completion.
snapshot_projects = (opts) ->

        (cb) ->
             # create the lock
             lock = misc.to_json
                    expire    : misc.walltime() + opts.ttl
                    server_id : server_id
             misc_node.execute_code
                 command : 'ssh'
                 args    : [user, "mkdir -p .bup; echo '#{lock}' > '#{opts.lockfile}'"]
