Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MongoDriver->getETag() can return the same etag for two different timestamps if they are within ~500 milliseconds #131

Open
kiyanwang opened this issue Dec 5, 2018 · 0 comments
Labels

Comments

@kiyanwang
Copy link
Member

kiyanwang commented Dec 5, 2018

The following method, computes an ETag for a document based on its _UPDATED_TS:

    public function getETag($resource,$context=null)
    {
        $this->getStat()->increment(MONGO_GET_ETAG);
        $resource = $this->labeller->uri_to_alias($resource);
        $query = array(
            "_id" => array(
                _ID_RESOURCE=>$resource,
                _ID_CONTEXT=>$this->getContextAlias($context)));
        $doc = $this->collection->findOne($query,array('projection' => array(_UPDATED_TS=>true)));
        /* @var $lastUpdatedDate UTCDateTime */
        $lastUpdatedDate = ($doc!=null && array_key_exists(_UPDATED_TS,$doc)) ? $doc[_UPDATED_TS] : null;
        if (isset($lastUpdatedDate) == null) {
            $eTag = '';
        } else {
            // PHP 5.3 used MongoDate::__toString() to generate the etag.
            // This is incompatible with UTCDate::__toString() so we convert it into a microtime representation.
            // This ensures that if it is required to dual run 2 PHP versions, there are no etag compatibility issues.
            // Note that MongoDate doesn't go to 8 decimal place precision but still returns it so we go to 6 and pad
            // with an extra 2
            $seconds = $lastUpdatedDate->__toString() / 1000;
            $eTag = str_pad(number_format(($seconds - floor($seconds)), 6), 10, '0', STR_PAD_RIGHT) . ' ' . floor($seconds);
        }
        return $eTag;

In principle, saving a change to a document, should result in a different value being computed for the Etag because the _UPDATED_TS will have changed. However this is not always the case. Based on the algorithm above, if the document is updated twice within ~500 milliseconds the same ETag is computed (floor rounds a number).

To demonstrate this I have created a branch (https://github.com/talis/tripod-php/tree/spike_etag_bug) with some unit tests that are failing because of this.

	// I've duplicated the core part of the algorithm in this helper method
    // db access is slower on travis ci so hard to get consistent reads
    // have therefore removed it from the equation altogether.
    protected function getETag() {
        $time = microtime(true);
        $lastUpdatedDate = new UTCDateTime($time);
        $seconds = $lastUpdatedDate->__toString() / 1000;
        $eTag = str_pad(number_format(($seconds - floor($seconds)), 6), 10, '0', STR_PAD_RIGHT) . ' ' . floor($seconds);
        return $eTag;
    }

    public function testETagAlgorithm10Millis()
    {
        $originalEtag = $this->getETag();
        usleep(10000);
        $secondEtag = $this->getETag();

        echo "First  ETag: " . $originalEtag . "\n";
        echo "  (10millis)\n";
        echo "Second ETag: " . $secondEtag . "\n\n";
        $this->assertNotEquals($originalEtag, $secondEtag);
    }

    public function testETagAlgorithm100Millis()
    {
        $originalEtag = $this->getETag();
        usleep(100000);
        $secondEtag = $this->getETag();

        echo "First  ETag: " . $originalEtag . "\n";
        echo " (100millis)\n";
        echo "Second ETag: " . $secondEtag . "\n\n";
        $this->assertNotEquals($originalEtag, $secondEtag);
    }

    public function testETagAlgorithm250Millis()
    {
        $originalEtag = $this->getETag();
        usleep(250000);
        $secondEtag = $this->getETag();

        echo "First  ETag: " . $originalEtag . "\n";
        echo " (250millis)\n";
        echo "Second ETag: " . $secondEtag . "\n\n";
        $this->assertNotEquals($originalEtag, $secondEtag);
    }

    public function testETagAlgorithm500Millis()
    {
        $originalEtag = $this->getETag();
        usleep(500000);
        $secondEtag = $this->getETag();

        echo "First  ETag: " . $originalEtag . "\n";
        echo " (500millis)\n";
        echo "Second ETag: " . $secondEtag . "\n\n";
        $this->assertNotEquals($originalEtag, $secondEtag);
    }

All of the above tests fail: https://travis-ci.org/talis/tripod-php/builds/463727103 consistently on PHP 7, 5.6 and 5.5. If I use a sleep duration greater than 500 milliseconds it fails intermittently, and at a second it always seems to work.

@kiyanwang kiyanwang added the bug label Dec 5, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

1 participant