2

I am struggling with a interesting problem of Cassandra nodes just using up more and more memory on disk for no apparent reason. The schema is an append only data model of event data that should be deleted after a fairly short period of time (24h). The table is using a TTL of 24 hours and we are using TWCS with a 1 day window size.

After some investigation into sstableexpiredblockers and doing a fair amount of sstabledump I found out that there are a lot of old sstables (2022-10-05 being the oldest) still around with records that have a liveness_info like this:

"liveness_info" : { "tstamp" : "2250-12-20T13:58:36.059597Z", "ttl" : 604800, "expires_at" : "2022-03-27T14:55:13Z", "expired" : true },

As you can see, it says expired: true, but the tstamp is in the future.

What could cause this future tstamp? My current suspicion is that these timestamps keep the data from being deleted - as these SSTables even survive user-triggered compactions. All the nodes run ntp correctly and we don't do any timestamp overrides on insert (we use gocql for writing). Cassandra is running version 3.11.12

I also tried querying the data (using the PK from sstabledump) and I get no results - so somehow Cassandra considers the data expired, it's just not being deleted from disk - and that blocks other sstables from being deleted.

The whole record looks like this:

"rows" : [
      {
        "type" : "row",
        "position" : 4671471,
        "clustering" : [ "0f67db7e-e0e0-495c-95a1-5038befe09a7", 58 ],
        "liveness_info" : { "tstamp" : "2250-12-20T13:58:36.059597Z", "ttl" : 604800, "expires_at" : "2022-03-27T14:55:13Z", "expired" : true },
        "cells" : [
          { "name" : "data", "deletion_info" : { "local_delete_time" : "2022-03-20T14:55:13Z" }
          }
        ]
      }

Has anyone seen this before and if so any ideas what could cause this and how to fix it?

2 Answers 2

2

Unsurprisingly, I haven't come across this issue before. I've tried to come up with possible scenarios that would cause the timestamp to be in the future and the only way I could think of is when it has been explicitly set with USING TIMESTAMP.

You will need to dig a bit deeper to determine the possibility that data wasn't inserted incorrectly that has lead to this. Cheers!

5
  • Hi Eric, I thought the same and have been investigating the code in question, but there is really no way we were ever inserting data incorrectly or USING TIMESTAMP. There is exactly one application inserting data here and I can't figure out how such a tstamp could have happened 🤷‍♀️ I've fixed the one table now by simply truncating the data - but really at a loss how it could have happened.
    – Tigraine
    Commented Feb 16, 2023 at 9:16
  • The only explanation I could think of is that the application doing the inserting had a mi-configured timestamp and the driver code somehow implicitly uses the client time instead of the Cassandra server time. Also interestingly enough - two tables that had issues with TWCS not cleaning up both started exhibiting the issue on Oct 5th.
    – Tigraine
    Commented Feb 16, 2023 at 9:17
  • So it happened again and I am pretty much absolutely sure there is nothing writing with USE TIMESTAMP right now. Still sstableblockers now shows a bunch of blocked tables because of this: gist.github.com/Tigraine/ec06bc66e1a099e4dca1078d5aca5cf0 Really can't understand how this could even happen but also it feels very random. Is there maybe some way a incorrectly set timestamp on clients can act up like this?
    – Tigraine
    Commented Feb 20, 2023 at 8:43
  • 1
    Maximum timestamp: 4270051401267032369 = 24 Apr 2105 or 82 years in the future. Have you checked (a) the time + (b) the TZ on (c) ALL nodes + (d) ALL app servers? Do they all have NTP configured? Commented Feb 22, 2023 at 5:35
  • Thanks for the help here Erick - we finally figured out what the issue was - I've added an answer for others to find here.
    – Tigraine
    Commented Jul 31, 2023 at 6:47
1

I've found the solution and wanted to share it here for others to find:

Protocol v3 supports using the client-supplied timestamps as the primary timestamp. This enables consistency even with out-of-order processing on the server (eg. under congestion or just through network latency) instead of the server-time of when the command was received.

The gocql driver uses client side timestamps by default through the DefaultTimestamp setting and that caused the timestamp issues in our application. Since we are using auto-scaled instances it seems sometimes an instance would come up and start writing while still in the process of receiving NTP updates. Those inserts would then be all over the place and cause these far-future timestamps in Cassandra.

Since our use-case/schema has no race conditions where last-write-wins would be relevant we disabled the DefaultTimestamp setting in gocql and since then our TWCS has been behaving correctly in deleting old SSTables.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.