While working on my MantaV2, I noted an unexpected behavior in the garbage-collector. When replacing an object, no garbage was being collected. I have traced this to a set of functions that appear to have never been completed in this new context. Functional, but rough, patches have been created.

Test case:

dd if=/dev/urandom of=testfile1 bs=128 count=3;
mput -f testfile1 ~~/stor/testfile1;  mrm ~~/stor/testfile1

If watching any part of the garbage-collection system (moray, postgres, the garbage-collection jobs) you should, and do see, an object get enqueued for deletion, and then deleted from the storage nodes.

Broken case:

dd if=/dev/urandom of=testfile1 bs=128 count=3;
dd if=/dev/urandom of=testfile2 bs=128 count=3;
mput -f testfile1 ~~/stor/testfile;  mput -f testfile2 ~~/stor/testfile

If watching any part of the garbage-collection system (moray, postgres, the garbage-collection jobs) you should but do not see, an object get enqueued for deletion, and then deleted from the storage nodes. That object being the first time testfile was uploaded, now replaced by the second time testfile was uploaded.

Trace of the bug

Both of these paths are relying on the post function in the Manta's Moray, as documented at https://github.com/TritonDataCenter/moray/blob/master/docs/index.md#triggers . In my Manta's moray, I find:

[root@56abbdbb (moray) ~]$ getbucket manta
{
  "name": "manta",
  "index": {
    "dirname": {
      "type": "string"
    },
    "name": {
      "type": "string"
    },
    "owner": {
      "type": "string"
    },
    "objectId": {
      "type": "string"
    },
    "type": {
      "type": "string"
    }
  },
  "pre": [],
  "post": [
    "function recordDeleteLog(req, cb) {\n    var microtime = require('microtime');\n    var crc = require('crc');\n\n    var log = req.log;\n    log.debug({\n        id: req.id,\n        bucket: req.bucket,\n        key: req.key,\n        value: req.value,\n        headers: req.headers\n    }, 'recordDeleteLog entered.');\n    var prevmd = req.headers['x-muskie-prev-metadata'];\n    if (!prevmd || !prevmd.objectId) {\n        log.debug('not logging without previous metadata');\n        cb();\n        return;\n    }\n    var prevObjectId = prevmd.objectId;\n\n    if (req.value && req.value.objectId &&\n        prevObjectId === req.value.objectId) {\n        log.debug('not logging since object === prev object');\n        cb();\n        return;\n    }\n    log.debug('object ' + prevObjectId + ' is candidate for deletion.');\n\n    // now log to the manta_delete_log table or the manta_fastdelete_queue...\n    var now = Math.round((microtime.now() / 1000));\n    var _key = '/' + prevObjectId + '/' + now;\n    var _value = JSON.stringify(prevmd);\n    var _etag = crc.hex32(crc.crc32(_value));\n    var _mtime = now;\n    var sql = '';\n    var values = [];\n\n    // If snaplinks are disabled use the fastdelete_queue rather than delete_log\n    if (req.headers['x-muskie-snaplinks-disabled']) {\n        log.debug('object ' + prevObjectId + ' being added to fastdelete.');\n        sql = 'INSERT INTO manta_fastdelete_queue (_key, _value, _etag, ' +\n            '_mtime) VALUES ($1, $2, $3, $4)';\n        values = [prevObjectId, _value, _etag, _mtime];\n    } else {\n        sql = 'INSERT INTO manta_delete_log (_key, _value, _etag, ' +\n            '_mtime, objectId) VALUES ($1, $2, $3, $4, $5)';\n        values = [_key, _value, _etag, _mtime, prevObjectId];\n    }\n\n    // execute\n    var q = req.pg.query(sql, values);\n    q.once('error', function (err) {\n        log.debug(err, 'manta delete log insert: failed');\n        cb(err);\n    });\n    q.once('end', function () {\n        log.debug('manta delete log insert: done');\n        cb();\n    });\n}"
  ],
  "options": {
    "version": 2
  },
  "mtime": "2019-04-02T17:42:48.794Z"
}

which has a post function, which is much easier to read here:

https://github.com/TritonDataCenter/node-libmanta/blob/a6e8094eed543afb5feddcf15d620d3e8dc06f78/lib/moray.js#L295

Relevant here is the line

https://github.com/TritonDataCenter/node-libmanta/blob/a6e8094eed543afb5feddcf15d620d3e8dc06f78/lib/moray.js#L333

which looks for the header x-muskie-snaplinks-disabled which then chooses to use the manta_fastdelete_queue which is the expected way garbage collection works in MantaV2.

So, implicitly this is getting set during the mrm operation, but not the mput operation, why is that? What even sets that?

Again, node-libmanta.

https://github.com/TritonDataCenter/node-libmanta/blob/a6e8094eed543afb5feddcf15d620d3e8dc06f78/lib/moray.js#L991

but notably, only in the delMetadata function. delMetadata is called by

https://github.com/TritonDataCenter/manta-muskie/blob/c9eec89d33d3aa86b1d372a6817c7288f4d46f75/lib/obj.js#L1036

muskie at deletePointer. This explains why mrm works.

So, why doesn't this work for the replacement operation?

Because

https://github.com/TritonDataCenter/manta-muskie/blob/c9eec89d33d3aa86b1d372a6817c7288f4d46f75/lib/obj.js#L640

saveMetadata doesn't call delMetadata. saveMetadata calls moray.putMetadata

https://github.com/TritonDataCenter/manta-muskie/blob/c9eec89d33d3aa86b1d372a6817c7288f4d46f75/lib/obj.js#L656

https://github.com/TritonDataCenter/node-libmanta/blob/a6e8094eed543afb5feddcf15d620d3e8dc06f78/lib/moray.js#L754

moray-libmanta's putMetadata has not handling for adding the header x-muskie-snaplinks-disabled at all.

So, in the case where an object is replaced with another object, the header never gets attached, the post code takes the other path, and the delete get written to the log, rather than the fastdelete table.

Proposed solution:

Add options on the calls on the replacement path similar if not identical to the delete path.

I have two branches on the two projects that have a rough patch, which copies in the logic for snaplink detection and relaying that information to moray. They are

I am running this on one of my webapi instances via in place editing, and it does not appear to be malfunctioning. I have not setup a more extensive test environment.

TritonDataCenter / manta-muskie

Mantav2 fails to garbage collect objects on object replacement #106

Trace of the bug

Proposed solution: