|
| 1 | +/* |
| 2 | + * Licensed to the Apache Software Foundation (ASF) under one or more |
| 3 | + * contributor license agreements. See the NOTICE file distributed with |
| 4 | + * this work for additional information regarding copyright ownership. |
| 5 | + * The ASF licenses this file to You under the Apache License, Version 2.0 |
| 6 | + * (the "License"); you may not use this file except in compliance with |
| 7 | + * the License. You may obtain a copy of the License at |
| 8 | + * |
| 9 | + * http://www.apache.org/licenses/LICENSE-2.0 |
| 10 | + * |
| 11 | + * Unless required by applicable law or agreed to in writing, software |
| 12 | + * distributed under the License is distributed on an "AS IS" BASIS, |
| 13 | + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 14 | + * See the License for the specific language governing permissions and |
| 15 | + * limitations under the License. |
| 16 | + */ |
| 17 | + |
| 18 | +package org.apache.spark.scheduler |
| 19 | + |
| 20 | +import java.util.{HashMap, Locale, Properties} |
| 21 | + |
| 22 | +import org.apache.spark.internal.{LogEntry, Logging, LogKeys, MessageWithContext} |
| 23 | + |
| 24 | +/** |
| 25 | + * A logging trait for scheduler components where log messages should include |
| 26 | + * structured streaming identifiers (query ID and batch ID). |
| 27 | + * |
| 28 | + * Streaming execution sets these identifiers via |
| 29 | + * [[org.apache.spark.SparkContext#setLocalProperty]], which is thread-local. |
| 30 | + * Scheduler code typically runs on a different thread (e.g. the |
| 31 | + * task-scheduler-event-loop-worker), so `getLocalProperty` would not have |
| 32 | + * the streaming context. This trait instead reads the identifiers from the |
| 33 | + * task's [[java.util.Properties]], which are propagated with the |
| 34 | + * [[org.apache.spark.scheduler.TaskSet]] across thread boundaries. |
| 35 | + * |
| 36 | + * Mix this trait into any scheduler component that has access to task |
| 37 | + * properties and needs streaming-aware log output. |
| 38 | + */ |
| 39 | +private[scheduler] trait StructuredStreamingIdAwareSchedulerLogging extends Logging { |
| 40 | + // we gather the query and batch Id from the properties of a given TaskSet |
| 41 | + protected def properties: Properties |
| 42 | + protected def streamingIdAwareLoggingEnabled: Boolean |
| 43 | + protected def streamingQueryIdLength: Int |
| 44 | + |
| 45 | + override protected def logInfo(msg: => String): Unit = |
| 46 | + super.logInfo( |
| 47 | + StructuredStreamingIdAwareSchedulerLogging |
| 48 | + .constructStreamingLogEntry( |
| 49 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 50 | + |
| 51 | + override protected def logInfo(entry: LogEntry): Unit = { |
| 52 | + super.logInfo( |
| 53 | + StructuredStreamingIdAwareSchedulerLogging |
| 54 | + .constructStreamingLogEntry( |
| 55 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 56 | + } |
| 57 | + |
| 58 | + override protected def logInfo(msg: => String, t: Throwable): Unit = |
| 59 | + super.logInfo( |
| 60 | + StructuredStreamingIdAwareSchedulerLogging |
| 61 | + .constructStreamingLogEntry( |
| 62 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 63 | + |
| 64 | + override protected def logInfo(entry: LogEntry, t: Throwable): Unit = { |
| 65 | + super.logInfo( |
| 66 | + StructuredStreamingIdAwareSchedulerLogging |
| 67 | + .constructStreamingLogEntry( |
| 68 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 69 | + } |
| 70 | + |
| 71 | + override protected def logWarning(msg: => String): Unit = |
| 72 | + super.logWarning( |
| 73 | + StructuredStreamingIdAwareSchedulerLogging |
| 74 | + .constructStreamingLogEntry( |
| 75 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 76 | + |
| 77 | + override protected def logWarning(entry: LogEntry): Unit = { |
| 78 | + super.logWarning( |
| 79 | + StructuredStreamingIdAwareSchedulerLogging |
| 80 | + .constructStreamingLogEntry( |
| 81 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 82 | + } |
| 83 | + |
| 84 | + override protected def logWarning(msg: => String, t: Throwable): Unit = |
| 85 | + super.logWarning( |
| 86 | + StructuredStreamingIdAwareSchedulerLogging |
| 87 | + .constructStreamingLogEntry( |
| 88 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 89 | + |
| 90 | + override protected def logWarning(entry: LogEntry, t: Throwable): Unit = { |
| 91 | + super.logWarning( |
| 92 | + StructuredStreamingIdAwareSchedulerLogging |
| 93 | + .constructStreamingLogEntry( |
| 94 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 95 | + } |
| 96 | + |
| 97 | + override protected def logDebug(msg: => String): Unit = |
| 98 | + super.logDebug( |
| 99 | + StructuredStreamingIdAwareSchedulerLogging |
| 100 | + .constructStreamingLogEntry( |
| 101 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 102 | + |
| 103 | + override protected def logDebug(entry: LogEntry): Unit = { |
| 104 | + super.logDebug( |
| 105 | + StructuredStreamingIdAwareSchedulerLogging |
| 106 | + .constructStreamingLogEntry( |
| 107 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 108 | + } |
| 109 | + |
| 110 | + override protected def logDebug(msg: => String, t: Throwable): Unit = |
| 111 | + super.logDebug( |
| 112 | + StructuredStreamingIdAwareSchedulerLogging |
| 113 | + .constructStreamingLogEntry( |
| 114 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 115 | + |
| 116 | + override protected def logDebug(entry: LogEntry, t: Throwable): Unit = { |
| 117 | + super.logDebug( |
| 118 | + StructuredStreamingIdAwareSchedulerLogging |
| 119 | + .constructStreamingLogEntry( |
| 120 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 121 | + } |
| 122 | + |
| 123 | + override protected def logError(msg: => String): Unit = |
| 124 | + super.logError( |
| 125 | + StructuredStreamingIdAwareSchedulerLogging |
| 126 | + .constructStreamingLogEntry( |
| 127 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 128 | + |
| 129 | + override protected def logError(entry: LogEntry): Unit = { |
| 130 | + super.logError( |
| 131 | + StructuredStreamingIdAwareSchedulerLogging |
| 132 | + .constructStreamingLogEntry( |
| 133 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 134 | + } |
| 135 | + |
| 136 | + override protected def logError(msg: => String, t: Throwable): Unit = |
| 137 | + super.logError( |
| 138 | + StructuredStreamingIdAwareSchedulerLogging |
| 139 | + .constructStreamingLogEntry( |
| 140 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 141 | + |
| 142 | + override protected def logError(entry: LogEntry, t: Throwable): Unit = { |
| 143 | + super.logError( |
| 144 | + StructuredStreamingIdAwareSchedulerLogging |
| 145 | + .constructStreamingLogEntry( |
| 146 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 147 | + } |
| 148 | + |
| 149 | + override protected def logTrace(msg: => String): Unit = |
| 150 | + super.logTrace( |
| 151 | + StructuredStreamingIdAwareSchedulerLogging |
| 152 | + .constructStreamingLogEntry( |
| 153 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 154 | + |
| 155 | + override protected def logTrace(entry: LogEntry): Unit = { |
| 156 | + super.logTrace( |
| 157 | + StructuredStreamingIdAwareSchedulerLogging |
| 158 | + .constructStreamingLogEntry( |
| 159 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength)) |
| 160 | + } |
| 161 | + |
| 162 | + override protected def logTrace(msg: => String, t: Throwable): Unit = |
| 163 | + super.logTrace( |
| 164 | + StructuredStreamingIdAwareSchedulerLogging |
| 165 | + .constructStreamingLogEntry( |
| 166 | + properties, msg, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 167 | + |
| 168 | + override protected def logTrace(entry: LogEntry, t: Throwable): Unit = { |
| 169 | + super.logTrace( |
| 170 | + StructuredStreamingIdAwareSchedulerLogging |
| 171 | + .constructStreamingLogEntry( |
| 172 | + properties, entry, streamingIdAwareLoggingEnabled, streamingQueryIdLength), t) |
| 173 | + } |
| 174 | +} |
| 175 | + |
| 176 | +/** |
| 177 | + * Helpers for constructing log entries enriched with structured streaming |
| 178 | + * identifiers extracted from task properties. |
| 179 | + */ |
| 180 | +private[scheduler] object StructuredStreamingIdAwareSchedulerLogging extends Logging { |
| 181 | + val QUERY_ID_KEY = "sql.streaming.queryId" |
| 182 | + val BATCH_ID_KEY = "streaming.sql.batchId" |
| 183 | + |
| 184 | + private[scheduler] def constructStreamingLogEntry( |
| 185 | + properties: Properties, |
| 186 | + entry: LogEntry, |
| 187 | + enabled: Boolean, |
| 188 | + queryIdLength: Int): LogEntry = { |
| 189 | + if (!enabled || properties == null) { |
| 190 | + return entry |
| 191 | + } |
| 192 | + // wrap in log entry to defer until log is evaluated |
| 193 | + new LogEntry({ |
| 194 | + val (queryId: Option[String], batchId: Option[String]) = |
| 195 | + getStreamingProperties(properties, queryIdLength) |
| 196 | + |
| 197 | + formatMessage( |
| 198 | + queryId, |
| 199 | + batchId, |
| 200 | + entry |
| 201 | + ) |
| 202 | + }) |
| 203 | + } |
| 204 | + |
| 205 | + private[scheduler] def constructStreamingLogEntry( |
| 206 | + properties: Properties, |
| 207 | + msg: => String, |
| 208 | + enabled: Boolean, |
| 209 | + queryIdLength: Int): LogEntry = { |
| 210 | + if (!enabled || properties == null) { |
| 211 | + return new LogEntry( |
| 212 | + MessageWithContext(msg, java.util.Collections.emptyMap()) |
| 213 | + ) |
| 214 | + } |
| 215 | + |
| 216 | + new LogEntry({ |
| 217 | + val (queryId: Option[String], batchId: Option[String]) = |
| 218 | + getStreamingProperties(properties, queryIdLength) |
| 219 | + |
| 220 | + MessageWithContext( |
| 221 | + formatMessage( |
| 222 | + queryId, |
| 223 | + batchId, |
| 224 | + msg |
| 225 | + ), |
| 226 | + constructStreamingContext(queryId, batchId) |
| 227 | + ) |
| 228 | + }) |
| 229 | + } |
| 230 | + |
| 231 | + private def constructStreamingContext( |
| 232 | + queryId: Option[String], |
| 233 | + batchId: Option[String]): HashMap[String, String] = { |
| 234 | + val streamingContext = new HashMap[String, String]() |
| 235 | + // MDC places the log key in the context as all lowercase, so we do the same here |
| 236 | + queryId.foreach(streamingContext.put(LogKeys.QUERY_ID.name.toLowerCase(Locale.ROOT), _)) |
| 237 | + batchId.foreach(streamingContext.put(LogKeys.BATCH_ID.name.toLowerCase(Locale.ROOT), _)) |
| 238 | + streamingContext |
| 239 | + } |
| 240 | + |
| 241 | + private def formatMessage( |
| 242 | + queryId: Option[String], |
| 243 | + batchId: Option[String], |
| 244 | + msg: => String): String = { |
| 245 | + val msgWithBatchId = batchId.map(bid => s"[batchId = $bid] $msg").getOrElse(msg) |
| 246 | + queryId.map(qId => s"[queryId = $qId] $msgWithBatchId").getOrElse(msgWithBatchId) |
| 247 | + } |
| 248 | + |
| 249 | + private def formatMessage( |
| 250 | + queryId: Option[String], |
| 251 | + batchId: Option[String], |
| 252 | + msg: => LogEntry): MessageWithContext = { |
| 253 | + val msgWithBatchId: MessageWithContext = batchId.map( |
| 254 | + bId => log"[batchId = ${MDC(LogKeys.BATCH_ID, bId)}] " + toMessageWithContext(msg) |
| 255 | + ).getOrElse(toMessageWithContext(msg)) |
| 256 | + queryId.map( |
| 257 | + qId => log"[queryId = ${MDC(LogKeys.QUERY_ID, qId)}] " + msgWithBatchId |
| 258 | + ).getOrElse(msgWithBatchId) |
| 259 | + } |
| 260 | + |
| 261 | + private def toMessageWithContext(entry: LogEntry): MessageWithContext = { |
| 262 | + MessageWithContext(entry.message, entry.context) |
| 263 | + } |
| 264 | + |
| 265 | + private def getStreamingProperties( |
| 266 | + properties: Properties, |
| 267 | + queryIdLength: Int): (Option[String], Option[String]) = { |
| 268 | + val queryId = Option(properties.getProperty(QUERY_ID_KEY)).filter(_.nonEmpty).map { id => |
| 269 | + if (queryIdLength == -1) { |
| 270 | + id |
| 271 | + } else { |
| 272 | + id.take(queryIdLength) |
| 273 | + } |
| 274 | + } |
| 275 | + val batchId = Option(properties.getProperty(BATCH_ID_KEY)).filter(_.nonEmpty) |
| 276 | + (queryId, batchId) |
| 277 | + } |
| 278 | +} |
0 commit comments