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.

Sign up for GitHub

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

Jump to bottom

Sai slow logging WIP DO NOT REVIEW OR MERGE #1285

Draft
wants to merge 2 commits into
base: main
Choose a base branch
from
Draft

Sai slow logging WIP DO NOT REVIEW OR MERGE #1285

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
8791cc3
Slow SAI queries logging
ekaterinadimitrova2 Sep 13, 2024
e9f120a
WIP redaction
ekaterinadimitrova2 Sep 18, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 7 additions & 1 deletion src/java/org/apache/cassandra/config/CassandraRelevantProperties.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -497,7 +497,13 @@ public enum CassandraRelevantProperties
* Allows custom implementation of {@link org.apache.cassandra.sensors.RequestSensorsFactory} to optionally create
* and configure {@link org.apache.cassandra.sensors.RequestSensors} instances.
*/
REQUEST_SENSORS_FACTORY("cassandra.request_sensors_factory_class");
REQUEST_SENSORS_FACTORY("cassandra.request_sensors_factory_class"),

/**
* SAI slow log parameters
*/
SLOW_SAI_QUERY_BUFFER_SIZE("cassandra.slow_sai_query_buffer_size", "8192"),
SLOW_SAI_QUERY_BUFFER_PROCESSING_DELAY_MS("cassandra.slow_sai_query_buffer_processing_delay_ms", "1000");
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

1s is a lot.
A laptop can sometimes perform 20-30k SAI queries per second.
This is not unlikely to overflow the buffer size, and also may keep many plans in memory.

Not sure why we need this delay at all.
Could we not trigger the task of processing this queue whenever we insert something to the queue?

Copy link
Collaborator Author

@ekaterinadimitrova2 ekaterinadimitrova2 Sep 19, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more. 

1s is a lot.
A laptop can sometimes perform 20-30k SAI queries per second.
This is not unlikely to overflow the buffer size, and also may keep many plans in memory.

Yes, especially when I forgot the lower bound check that we should not log anything below let's say 200ms (I think this is the default in DSE, for example).

Not sure why we need this delay at all.
Could we not trigger the task of processing this queue whenever we insert something to the queue?

I believe to reduce the contention? For reference - the DSE ticket I linked in the internal issue.


CassandraRelevantProperties(String key, String defaultVal)
{
Expand Down
1 change: 1 addition & 0 deletions src/java/org/apache/cassandra/config/Config.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -119,6 +119,7 @@ public class Config
public boolean cross_node_timeout = true;

public volatile long slow_query_log_timeout_in_ms = 500L;
public volatile int sai_slow_log_num_slowest_queries = 5;

public volatile double phi_convict_threshold = 8.0;

Expand Down
14 changes: 14 additions & 0 deletions src/java/org/apache/cassandra/config/DatabaseDescriptor.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -976,6 +976,8 @@ else if (conf.max_value_size_in_mb >= 2048)
throw new ConfigurationException("aggregation_subpage_size_in_kb must be greater than 0");

setAggregationSubPageSize(getAggregationSubPageSize());

validateSaiSlowLogNumSlowestQueries();
}

@VisibleForTesting
Expand Down Expand Up @@ -1776,6 +1778,11 @@ public static long getSlowQueryTimeout(TimeUnit units)
return units.convert(conf.slow_query_log_timeout_in_ms, MILLISECONDS);
}

public static int getSaiSlowLogNumSlowestQueries()
{
return conf.sai_slow_log_num_slowest_queries;
}

/**
* @return the minimum configured {read, write, range, truncate, misc} timeout
*/
Expand Down Expand Up @@ -3690,6 +3697,13 @@ public static void setAggregationSubPageSize(PageSize pageSize)
conf.aggregation_subpage_size_in_kb = pageSize.bytes() / 1024;
}

public static void validateSaiSlowLogNumSlowestQueries()
{
// KATE the error message to be corrected after we decide on configuration/tooling
if (conf.sai_slow_log_num_slowest_queries < 1)
throw new ConfigurationException("sai_slow_log_num_slowest_queries must be greater than 0. To disable the slow log - use the enable/disable flag instead.");
}

public static ParameterizedClass getDefaultCompaction()
{
return conf != null ? conf.default_compaction : null;
Expand Down
92 changes: 84 additions & 8 deletions src/java/org/apache/cassandra/db/filter/RowFilter.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -250,6 +250,11 @@ public String toString()
return root.toString();
}

public String toStringRedacted()
{
return root.toStringRedacted();
}

private void warnIfFilterIsATree()
{
if (!root.children.isEmpty())
Expand Down Expand Up @@ -477,20 +482,38 @@ public boolean isSatisfiedBy(TableMetadata table, DecoratedKey key, Row row)

@Override
public String toString()
{
return toStringInternal(false);
}

public String toStringRedacted()
{
return toStringInternal(true);
}

private String toStringInternal(boolean redacted)
{
StringBuilder sb = new StringBuilder();
for (int i = 0; i < expressions.size(); i++)
{
if (sb.length() > 0)
sb.append(isDisjunction ? " OR " : " AND ");
sb.append(expressions.get(i));

if (!redacted)
sb.append(expressions.get(i));
else
sb.append(expressions.get(i).toStringRedacted());

Comment on lines +502 to +506
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could use sb.append(expressions.get(i).toStringInternal(redacted).

}
for (int i = 0; i < children.size(); i++)
{
if (sb.length() > 0)
sb.append(isDisjunction ? " OR " : " AND ");
sb.append("(");
sb.append(children.get(i));
if (!redacted)
sb.append(children.get(i));
else
sb.append(children.get(i).toStringRedacted());
Comment on lines +513 to +516
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same as above

sb.append(")");
}
return sb.toString();
Expand Down Expand Up @@ -785,6 +808,16 @@ public boolean equals(Object o)
&& Objects.equal(this.value, that.value);
}

public String toString()
{
return "";
}

public String toStringRedacted()
{
return "<redacted>";
}

Comment on lines +816 to +820
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Question: Why are we redacting all parameters? Parameter values contain important information about the query.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe we can keep the numbers, I think that the only "privacy sensitive" data are strings or collections/structures that may contain strings.
we can keep the numbers and vectors for instance, but if we don't know the datatype then it is fine to redact everything

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

what happend with query with binding variables ? are they represented here with the actual value ?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

what happend with query with binding variables ? are they represented here with the actual value ?
Yes, they are; the "test" that I added was intentional with a prepared statement.

maybe we can keep the numbers, I think that the only "privacy sensitive" data are strings or collections/structures that may contain strings.
we can keep the numbers and vectors for instance, but if we don't know the datatype then it is fine to redact everything

That sounds like a good idea. I will run it through Pushkala just in case

@Override
public int hashCode()
{
Expand Down Expand Up @@ -1046,8 +1079,8 @@ private boolean containsKey(TableMetadata metadata, DecoratedKey partitionKey, R
}
}

@Override
public String toString()

private String toStringInternal(boolean redacted)
{
AbstractType<?> type = column.type;
switch (operator)
Expand All @@ -1074,12 +1107,32 @@ public String toString()
default:
break;
}
var valueString = type.getString(value);
if (valueString.length() > 9)
valueString = valueString.substring(0, 6) + "...";

String valueString;
if(redacted)
valueString = "<redacted>";
else
{
valueString = type.getString(value);
if (valueString.length() > 9)
valueString = valueString.substring(0, 6) + "...";
}

return String.format("%s %s %s", column.name, operator, valueString);
}

@Override
public String toString()
{
return toStringInternal(false);
}

@Override
public String toStringRedacted()
{
return toStringInternal(true);
}

@Override
protected Kind kind()
{
Expand Down Expand Up @@ -1185,9 +1238,24 @@ private boolean isSatisfiedByEq(TableMetadata metadata, DecoratedKey partitionKe

@Override
public String toString()
{
return toStringInternal(false);
}

@Override
public String toStringRedacted()
{
return toStringInternal(true);
}

private String toStringInternal(boolean redacted)
{
MapType<?, ?> mt = (MapType<?, ?>)column.type;
return String.format("%s[%s] %s %s", column.name, mt.nameComparator().getString(key), operator, mt.valueComparator().getString(value));

if(!redacted)
return String.format("%s[%s] %s %s", column.name, mt.nameComparator().getString(key), operator, mt.valueComparator().getString(value));

return String.format("%s[%s] %s %s", column.name, mt.nameComparator().getString(key), operator, "<redacted>");
}

@Override
Expand Down Expand Up @@ -1362,6 +1430,13 @@ public String toString()
distanceOperator, FloatType.instance.getString(distance));
}

@Override
public String toStringRedacted()
{
return String.format("GEO_DISTANCE(%s, %s) %s %s", column.name, "<redacted>",
distanceOperator, "<redacted>");
}

@Override
public boolean equals(Object o)
{
Expand Down Expand Up @@ -1432,6 +1507,7 @@ public ByteBuffer getValue()
return value;
}

@Override
public String toString()
{
return String.format("expr(%s, %s)",
Expand Down
Loading