LogCache returns data before requested `start_time`

poy commented 6 years ago

So I noticed an interesting thing, I can get data that is BEFORE the requested start_time:

$curl -s log-cache.<system-domain>/v1/read/<my-source-id>?start_time=1536303786797268742\&envelope_types=GAUGE\&envelope_types=COUNTER\&envelope_types=TIMER -H"Authorization: $(cf oauth-token)" | jq .

{
  "envelopes": {
    "batch": [
      {
        "timestamp": "1536303786797268741",
...
      }
    ]}
}

Note that 1536303786797268742 - 1536303786797268741 => 1 or start_time - envelopes.batch[0].timestamp

This has severe consequences for go-log-cache's Walk algorithm, as it will keep requesting the last timestamp +1... Which means that we are then requesting the same start_time as before. This implies we are in an infinite loop until our context expires.

cf-gitbot commented 6 years ago

We have created an issue in Pivotal Tracker to manage this:

https://www.pivotaltracker.com/story/show/160345801

The labels on this github issue will be updated when the story is started.

toddboom commented 6 years ago

@apoydence This is fixed by 751049535a51a7dd0700dbcbb4ac0184d77312d0.

cloudfoundry / log-cache

LogCache returns data before requested `start_time` #89