| /* |
| * 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. |
| */ |
| |
| import org.apache.tools.ant.BuildException |
| |
| // Checks logging calls to keep from using patterns that might be expensive |
| // either in CPU or unnecessary object creation. Some of the checks are a little |
| // over-zealous, but it's worth a bit of aggravation to catch the egregious |
| // mistakes before they accrue. |
| |
| // This all started with Java Flight Recorder showing a massive number of |
| // objects allocated and garbage collected. Tracing a bunch of them down showed |
| // that we have a number of calls like: |
| // log.debug("some string" + very_expensive_object_to_make_a_string). |
| // which _always_ constructed the very expensive ojbect even if the log level |
| // was INFO or more severe. Rather than leave lots of confusing formats laying |
| // about or expecting people to remember the rules, we opted to make this |
| // check part of Gradle precommit. It will be included by default in Solr |
| // 9.0. |
| |
| // See the associated help task "gradlew helpValidateLogCalls" |
| |
| configure(subprojects.findAll { it.path.startsWith(':solr') }) { |
| plugins.withType(JavaPlugin) { |
| task validateLogCalls(type: ValidateLogCallsTask) { task -> |
| description "Checks that log calls are either validated or conform to efficient patterns." |
| group "verification" |
| |
| // This task has no proper outputs. |
| setupDummyOutputs(task) |
| |
| sourceFiles = files(sourceSets*.java) |
| } |
| |
| // Add log validation to per-project checks as well. |
| check.dependsOn validateLogCalls |
| } |
| } |
| |
| class ValidateLogCallsTask extends DefaultTask { |
| def logLevels = ["log.trace", "log.debug", "log.info", "log.warn", "log.error", "log.fatal"] |
| |
| def errsFound = 0; |
| def violations = new ArrayList(); |
| |
| def reportViolation(String msg) { |
| violations.add(System.lineSeparator + msg); |
| errsFound++; |
| } |
| |
| // We have a log.something line, check for patterns we're not fond of. |
| def checkLine(File file, String line, int lineNumber, String previous) { |
| boolean violation = false |
| |
| // If the line has been explicitly OK'd, then it's OK! |
| if (line.replaceAll("\\s", "").toLowerCase().contains("//nowarn")) { |
| return |
| } |
| // Strip all of the comments, things in quotes and the like. |
| def stripped = |
| line.replaceFirst("//.*", " ") // remove comment to EOL. May be fragile due to the possibility of embedded double slashes |
| .replaceFirst(/.*?\(/, " ") // Get rid of "log.whatever(" |
| .replaceFirst(/\);/, " ") // get rid of the closing ");" |
| .replaceFirst("/\\*.*?\\*/", " ") // replace embedded comments "/*....*/" |
| .replaceAll(/".*?"/, '""') // remove anything between quotes. This is a bit fragile if there are embedded double quotes. |
| .replaceAll(/timeLeft\(.*?\)/, " ") // used all over tests, it's benign |
| .replaceAll(/TimeUnit\..*?\.convert\(.*?\)/, " ") // again, a pattern that's efficient |
| .replaceAll("\\s", "") |
| |
| // The compiler will pre-assemble patterns like 'log.info("string const1 {}" + " string const2 {}", obj1, obj2)' |
| // to log.info("string const1 {} string const2 {}", obj1, obj2)', so don't worry about any plus preceded and |
| // followed by double quotes, otherwise flag it. |
| def hasPlus = false |
| for (int idx = 0; idx < stripped.length(); ++idx) { |
| if (stripped.charAt(idx) == '+') { |
| if (idx == 0 || idx == stripped.length() - 1 |
| || stripped.charAt(idx - 1) != '"' || stripped.charAt(idx + 1) != '"') { |
| hasPlus = true |
| break |
| } |
| } |
| } |
| //TODO remove me |
| String cause = "" |
| // Get the level of this log message. |
| // We don't really care about checking for method calls for WARN and more severe, the presumption |
| // is that they _should_ always be reported. |
| |
| def level = "" |
| def lev = (line =~ "log\\.(.*?)\\(") |
| if (lev.find()) { |
| level = lev.group(1).toLowerCase().trim() |
| } |
| if (logLevels.contains("log." + level) == false) { |
| reportViolation(String.format("Found an unexpected log level: %s, file: %s:%d" |
| , level, file.getAbsolutePath(), lineNumber)) |
| } |
| boolean persnicketyLevel = !(level.equals("fatal") || level.equals("error") || level.equals("warn")) |
| |
| // Check that previous line isn't an if statement for always-reported log levels. |
| // There's a convention to declare a member variable for whether a level is enabled and check that rather than |
| // isDebugEnabled so we need to check both. |
| String prevLine = previous.replaceAll("\\s+", "").toLowerCase() |
| boolean prevLineNotIf = ((prevLine.contains("if(log.is" + level + "enabled") == false |
| && prevLine.contains("if(" + level + ")") == false)) |
| |
| if (hasPlus) { |
| cause = "hasPlus: " + hasPlus |
| violation = true |
| } |
| if (violation == false) { |
| def m = stripped =~ "\\(.*?\\)" |
| def hasParens = m.find() |
| |
| if (hasParens && prevLineNotIf && persnicketyLevel) { |
| cause = "hasParens " + hasParens + " prevLineNotIf " + prevLineNotIf + " pernicketyLevel " + persnicketyLevel |
| violation = true |
| } |
| } |
| |
| // Always report toString(). Note, this over-reports some constructs |
| // but just add //nowarn if it's really OK. |
| if (violation == false) { |
| if (line.contains("toString(") == true && prevLineNotIf) { |
| cause = "Line contains toString" |
| violation = true |
| } |
| } |
| if (stripped.contains("getMessage()") || stripped.contains("getCause()")) { |
| cause = "getMessage or getCause in log line"; |
| violation = true; |
| } |
| if (violation) { |
| reportViolation(String.format("cause: '%s' Suspicious logging call, Parameterize and possibly surround with 'if (log.is*Enabled) {..}'. Help at: 'gradlew helpValidateLogCalls' %s %s:%d" |
| , cause , System.lineSeparator, file.getAbsolutePath(), lineNumber)) |
| } |
| return |
| } |
| |
| // Require all our logger definitions lower case "log", except if they have //nowarn |
| def checkLogName(File file, String line) { |
| // It's many times faster to do check this way than use a regex |
| if (line.contains("static ") && line.contains("getLogger") && line.contains(" log ") == false) { |
| if (line.replaceAll("\\s", "").toLowerCase().contains("//nowarn")) { |
| return |
| } |
| reportViolation("Change the logger name to lower-case 'log' in " + file.name + " " + line + " project" + project) |
| } |
| } |
| |
| def checkFile(File file) { |
| int state = 0 |
| int lineNumber = 0 |
| StringBuilder sb = new StringBuilder(); |
| |
| // We have to assemble line-by-line to get the full log statement. We require that all loggers (except requestLog |
| // and slowLog) be exactly "log". That will be checked as well. |
| String prevLine = "" |
| file.eachLine { String line -> |
| lineNumber++ |
| checkLogName(file, line) |
| switch (state) { |
| case 0: // Not collecting a logging line. |
| logLevels.each { |
| if (line.contains(it)) { |
| if (line.contains(");")) { |
| state = 2 |
| } else { |
| state = 1 |
| } |
| sb.setLength(0) |
| sb.append(line) |
| } |
| } |
| break |
| |
| case 1: // collecting a log line |
| if (line.replaceFirst("//.*", " ") |
| .replaceFirst("/\\*.*?\\*/", " ") // replace embedded comments "/*....*/" |
| .replaceAll(/".*?"/, '""') // remove anything between quotes. This is a bit fragile if there are embedded double quotes. |
| .trim().endsWith(");")) { |
| state = 2 |
| } |
| sb.append(line) |
| break |
| |
| default: |
| reportViolation("Bad state, should be 0-1 in the switch statement") // make people aware the code sucks |
| break |
| } |
| |
| // It's just easier to do this here rather than read another line in the switch above. |
| if (state == 0) { |
| // Not collecting a log line |
| prevLine = line.toLowerCase(); |
| } else if (state == 1) { |
| // collecting a logging line. |
| } else if (state == 2) { |
| // We've collected the complete log line. |
| checkLine(file, sb.toString(), lineNumber, prevLine) |
| state = 0 |
| } else { |
| assert false |
| } |
| } |
| } |
| |
| @InputFiles |
| FileCollection sourceFiles |
| |
| @TaskAction |
| def checkLogLines() { |
| sourceFiles.each { checkFile(it) } |
| logger.info("Checked: ${sourceFiles.files.size()}") |
| |
| if (errsFound > 0) { |
| throw new BuildException(String.format(Locale.ENGLISH, 'Found %d violations in source files (%s).', |
| errsFound, violations.join(', '))); |
| } |
| } |
| } |
