Log Cassandra trace data if tracing is enabled

[nemines]

CQLKeyValueServices offer a logTracedQuery to bring performance traces stored into Cassandra to logs, if enabled.
It would be useful to have this in CassandraKeyValueService as well.

[gbrova]

This looks like a duplicate of #495

[nemines]

@gbrova I don't think it is. This is specifically referring to the existing tracing Cassandra feature for performance analysis. All that we need to do is enabling to use the existing Cassandra tracing data (ideally by logging what we're interested in). It's already done in the CQL kvs, just needs porting.

[tpetracca]

@nemines can you elaborate? In CassandraKVS I see:

    private <V> V run(Client client, Set<TableReference> tableRefs, Action<V> action) throws TException {
        if (shouldTraceQuery(tableRefs)) {
            return trace(action, client, tableRefs);
        } else {
            try {
                return action.run();
            } catch (TException e) {
                logFailedCall(tableRefs);
                throw e;
            }
        }
    }

    private <V> V run(Client client, TableReference tableRef, Action<V> action) throws TException {
        return run(client, ImmutableSet.of(tableRef), action);
    }

    private <V> V trace(Action<V> action, Client client, Set<TableReference> tableRefs) throws TException {
        ByteBuffer traceId = client.trace_next_query();
        Stopwatch stopwatch = Stopwatch.createStarted();
        boolean failed = false;
        try {
            return action.run();
        } catch (TException e) {
            failed = true;
            logFailedCall(tableRefs);
            throw e;
        } finally {
            long duration = stopwatch.elapsed(TimeUnit.MILLISECONDS);
            logTraceResults(duration, tableRefs, traceId, failed);
        }
    }

where an example of this being called is

run(client, tableRefs, () -> {
            client.batch_mutate(map, consistency);
            return true;
        });

[tpetracca]

Ooooh I just re-read your original post @nemines. Basically what you're saying is that you'd like us to make a way to actually pull the information that cassandra trace generates in system_traces and actually extract it from cassandra and write it to a log.

The bad part about this is that it makes enabling tracing that much more of a performance hit (as the cassandra trace on it's own already has impact, nevermind adding more round trips to cassandra). That being said we can probably do it in the short term anyway, and just make it another configuration point in the cassandra tracing (whether or not to log actual trace info instead of just trace ids).

The long term solution to this is using a cassandra version that supports generating zipkin style traces (http://thelastpickle.com/blog/2015/12/07/using-zipkin-for-full-stack-tracing-including-cassandra.html) and then integrating Brave into the various KVS' to be able to pass trace requests to cassandra. Requires openzipkin/brave#166 to be resolved as well, which @schlosna is working on.

[nemines]

Oh, now I get it too. It's fine for me if we want to wait for zipkin and close this one.
It would have been handy when I was working on the glutton perf project, but I'm not working on it anymore.
As a related the issue, I think the way we're logging the key for Cassandra tracing right now is broken, so that logging config is useless at the moment.

[rhero]

@nemines - what specifically is broken about it? Do you mind filing a separate ticket for that?

I'll close this one out with the understanding we'll eventually want a zipkin compatible Cassandra.

[nemines]

Last time I tried to use the id in the atlas log to access the traces stored in Cassandra I was not able to find anything matching in the KVS. I figured someone should check if it's actually working, because for me it wasn't.