gianm commented on a change in pull request #6302: Add SQL id, request logs, and metrics URL: https://github.com/apache/incubator-druid/pull/6302#discussion_r246159853
########## File path: sql/src/main/java/org/apache/druid/sql/SqlLifecycle.java ########## @@ -0,0 +1,361 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +package org.apache.druid.sql; + +import com.google.common.base.Preconditions; +import com.google.common.collect.Iterables; +import com.google.common.collect.Maps; +import org.apache.calcite.rel.type.RelDataType; +import org.apache.calcite.sql.parser.SqlParseException; +import org.apache.calcite.tools.RelConversionException; +import org.apache.calcite.tools.ValidationException; +import org.apache.druid.java.util.common.DateTimes; +import org.apache.druid.java.util.common.ISE; +import org.apache.druid.java.util.common.StringUtils; +import org.apache.druid.java.util.common.guava.Sequence; +import org.apache.druid.java.util.common.guava.SequenceWrapper; +import org.apache.druid.java.util.common.guava.Sequences; +import org.apache.druid.java.util.common.logger.Logger; +import org.apache.druid.java.util.emitter.service.ServiceEmitter; +import org.apache.druid.java.util.emitter.service.ServiceMetricEvent; +import org.apache.druid.query.QueryInterruptedException; +import org.apache.druid.server.QueryStats; +import org.apache.druid.server.RequestLogLine; +import org.apache.druid.server.log.RequestLogger; +import org.apache.druid.server.security.Access; +import org.apache.druid.server.security.AuthenticationResult; +import org.apache.druid.server.security.AuthorizationUtils; +import org.apache.druid.server.security.ForbiddenException; +import org.apache.druid.sql.calcite.planner.DruidPlanner; +import org.apache.druid.sql.calcite.planner.PlannerContext; +import org.apache.druid.sql.calcite.planner.PlannerFactory; +import org.apache.druid.sql.calcite.planner.PlannerResult; +import org.apache.druid.sql.http.SqlQuery; + +import javax.annotation.Nullable; +import javax.annotation.concurrent.ThreadSafe; +import javax.servlet.http.HttpServletRequest; +import java.util.LinkedHashMap; +import java.util.Map; +import java.util.UUID; +import java.util.concurrent.TimeUnit; + +@ThreadSafe +public class SqlLifecycle +{ + private static final Logger log = new Logger(SqlLifecycle.class); + + private final PlannerFactory plannerFactory; + private final ServiceEmitter emitter; + private final RequestLogger requestLogger; + private final long startMs; + private final long startNs; + private final Object lock = new Object(); + + private State state = State.NEW; + + // init during intialize + private String sql; + private Map<String, Object> queryContext; + // init during plan + private HttpServletRequest req; // may be null + private PlannerContext plannerContext; + private PlannerResult plannerResult; + + public SqlLifecycle( + PlannerFactory plannerFactory, + ServiceEmitter emitter, + RequestLogger requestLogger, + long startMs, + long startNs + ) + { + this.plannerFactory = plannerFactory; + this.emitter = emitter; + this.requestLogger = requestLogger; + this.startMs = startMs; + this.startNs = startNs; + } + + public String initialize(SqlQuery sqlQuery) + { + synchronized (lock) { + transition(State.NEW, State.INITIALIZED); + this.sql = sqlQuery.getQuery(); + this.queryContext = contextWithSqlId(sqlQuery.getContext()); + return sqlQueryId(); + } + } + + public String initialize(String sql, Map<String, Object> queryContext) + { + synchronized (lock) { + transition(State.NEW, State.INITIALIZED); + this.sql = sql; + this.queryContext = contextWithSqlId(queryContext); + return sqlQueryId(); + } + } + + private Map<String, Object> contextWithSqlId(Map<String, Object> queryContext) + { + Map<String, Object> newContext = Maps.newHashMap(); + if (queryContext != null) { + newContext.putAll(queryContext); + } + if (!newContext.containsKey(PlannerContext.CTX_SQL_QUERY_ID)) { + newContext.put(PlannerContext.CTX_SQL_QUERY_ID, UUID.randomUUID().toString()); + } + return newContext; + } + + private String sqlQueryId() + { + return (String) this.queryContext.get(PlannerContext.CTX_SQL_QUERY_ID); + } + + public PlannerContext plan(AuthenticationResult authenticationResult) + throws ValidationException, RelConversionException, SqlParseException + { + synchronized (lock) { + transition(State.INITIALIZED, State.PLANED); + try (DruidPlanner planner = plannerFactory.createPlanner(queryContext, authenticationResult)) { + this.plannerContext = planner.getPlannerContext(); + this.plannerResult = planner.plan(sql); + } + return plannerContext; + } + } + + public PlannerContext plan(HttpServletRequest req) + throws SqlParseException, RelConversionException, ValidationException + { + synchronized (lock) { + this.req = req; + return plan(AuthorizationUtils.authenticationResultFromRequest(req)); + } + } + + public RelDataType rowType() + { + synchronized (lock) { + Preconditions.checkState(plannerResult != null, + "must be call after sql has been planned"); + return plannerResult.rowType(); + } + } + + public Access authorize() + { + synchronized (lock) { + transition(State.PLANED, State.AUTHORIZING); + + if (req != null) { + return doAuthorize( + plannerContext.getAuthenticationResult(), + AuthorizationUtils.authorizeAllResourceActions( + req, + Iterables.transform( + plannerResult.datasourceNames(), + AuthorizationUtils.DATASOURCE_READ_RA_GENERATOR + ), + plannerFactory.getAuthorizerMapper() + ) + ); + } + + return doAuthorize( + plannerContext.getAuthenticationResult(), + AuthorizationUtils.authorizeAllResourceActions( + plannerContext.getAuthenticationResult(), + Iterables.transform(plannerResult.datasourceNames(), AuthorizationUtils.DATASOURCE_READ_RA_GENERATOR), + plannerFactory.getAuthorizerMapper() + ) + ); + } + } + + private Access doAuthorize(final AuthenticationResult authenticationResult, final Access authorizationResult) + { + if (!authorizationResult.isAllowed()) { + // Not authorized; go straight to Jail, do not pass Go. + transition(State.AUTHORIZING, State.UNAUTHORIZED); + } else { + transition(State.AUTHORIZING, State.AUTHORIZED); + } + return authorizationResult; + } + + public PlannerContext planAndAuthorize(final AuthenticationResult authenticationResult) + throws SqlParseException, RelConversionException, ValidationException + { + PlannerContext plannerContext = plan(authenticationResult); + Access access = authorize(); + if (!access.isAllowed()) { + throw new ForbiddenException(access.toString()); + } + return plannerContext; + } + + public PlannerContext planAndAuthorize(final HttpServletRequest req) + throws SqlParseException, RelConversionException, ValidationException + { + PlannerContext plannerContext = plan(req); + Access access = authorize(); + if (!access.isAllowed()) { + throw new ForbiddenException(access.toString()); + } + return plannerContext; + } + + public Sequence<Object[]> execute() + { + synchronized (lock) { + transition(State.AUTHORIZED, State.EXECUTING); + return plannerResult.run(); + } + } + + public Sequence<Object[]> runSimple( + String sql, + Map<String, Object> queryContext, + AuthenticationResult authenticationResult + ) throws ValidationException, RelConversionException, SqlParseException + { + Sequence<Object[]> result; + + initialize(sql, queryContext); + try { + planAndAuthorize(authenticationResult); + result = execute(); + } + catch (Throwable e) { + emitLogsAndMetrics(e, null, -1); + throw e; + } + + return Sequences.wrap(result, new SequenceWrapper() + { + @Override + public void after(boolean isDone, Throwable thrown) + { + emitLogsAndMetrics(thrown, null, -1); + } + }); + } + + /** + * Emit logs and metrics for this query. + * + * @param e exception that occurred while processing this query + * @param remoteAddress remote address, for logging; or null if unknown + * @param bytesWritten number of bytes written; will become a query/bytes metric if >= 0 + */ + public void emitLogsAndMetrics( + @Nullable final Throwable e, + @Nullable final String remoteAddress, + final long bytesWritten + ) + { + synchronized (lock) { + if (sql == null) { + // Never initialized, don't log or emit anything. + return; + } + + if (state == State.DONE) { + log.warn("Tried to emit logs and metrics twice for query[%s]!", sqlQueryId()); + } + + state = State.DONE; + + final boolean success = e == null; + final long queryTimeNs = System.nanoTime() - startNs; + + try { + ServiceMetricEvent.Builder metricBuilder = ServiceMetricEvent.builder(); + if (plannerContext != null) { + metricBuilder.setDimension("id", plannerContext.getSqlQueryId()); + metricBuilder.setDimension("nativeQueryIds", plannerContext.getNativeQueryIds().toString()); + } + if (plannerResult != null) { + metricBuilder.setDimension("dataSource", plannerResult.datasourceNames().toString()); + } + metricBuilder.setDimension("remoteAddress", StringUtils.nullToEmptyNonDruidDataString(remoteAddress)); + metricBuilder.setDimension("success", String.valueOf(success)); + emitter.emit(metricBuilder.build("sqlQuery/time", TimeUnit.NANOSECONDS.toMillis(queryTimeNs))); + if (bytesWritten >= 0) { + emitter.emit(metricBuilder.build("sqlQuery/bytes", bytesWritten)); + } + + final Map<String, Object> statsMap = new LinkedHashMap<>(); + statsMap.put("sqlQuery/time", TimeUnit.NANOSECONDS.toMillis(queryTimeNs)); + statsMap.put("sqlQuery/bytes", bytesWritten); + statsMap.put("success", success); + statsMap.put("context", queryContext); + if (plannerContext != null) { + statsMap.put("identity", plannerContext.getAuthenticationResult().getIdentity()); + queryContext.put("nativeQueryIds", plannerContext.getNativeQueryIds().toString()); + } + if (e != null) { + statsMap.put("exception", e.toString()); + + if (e instanceof QueryInterruptedException) { + statsMap.put("interrupted", true); + statsMap.put("reason", e.toString()); + } + } + + requestLogger.logSqlQuery( + RequestLogLine.forSql( + sql, + DateTimes.utc(startMs), + remoteAddress, + new QueryStats(statsMap) + ) + ); + } + catch (Exception ex) { + log.error(ex, "Unable to log sql [%s]!", sql); + } + } + } + + private void transition(final State from, final State to) + { + if (state != from) { + throw new ISE("Cannot transition from[%s] to[%s].", from, to); + } + + state = to; + } + + enum State + { + NEW, + INITIALIZED, + PLANED, Review comment: `PLANNED` (spelling) ---------------------------------------------------------------- This is an automated message from the Apache Git Service. To respond to the message, please log on GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: [email protected] With regards, Apache Git Services --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
