Skip to content

Commit

Permalink
Downgrade the default invocation policy log levels to fine.
Browse files Browse the repository at this point in the history 
Unfortunately, since the invocation policy gets enforced on a user's command line early in the command environment setup, so the effective log level is not yet set. For this run, keep the logs at INFO, since any other level will disappear into the ether.

InvocationPolicy gets enforced not only at invocation startup but also elsewhere to recompute the default values. The log statements from these different runs overwhelm the log output from our tests, making it hard to find other events without filtering the log. Make all extra invocation policy enforcements log at FINE so that they only appear when extra detail is requested.

PiperOrigin-RevId: 171151573
  • Loading branch information
@cvcal @aehlig
cvcal authored and aehlig committed Oct 6, 2017
1 parent 37fe24d commit 334d2f1
Show file tree
Hide file tree
Showing 3 changed files with 86 additions and 53 deletions.
3 changes: 2 additions & 1 deletion src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -712,7 +712,8 @@ private ExitCode parseOptions(
.mergeFrom(runtime.getModuleInvocationPolicy())
.mergeFrom(invocationPolicy)
.build();
InvocationPolicyEnforcer optionsPolicyEnforcer = new InvocationPolicyEnforcer(combinedPolicy);
InvocationPolicyEnforcer optionsPolicyEnforcer =
new InvocationPolicyEnforcer(combinedPolicy, Level.INFO);
// Enforce the invocation policy. It is intentional that this is the last step in preparing
// the options. The invocation policy is used in security-critical contexts, and may be used
// as a last resort to override flags. That means that the policy can override flags set in
Expand Down
3 changes: 2 additions & 1 deletion src/main/java/com/google/devtools/build/lib/runtime/commands/CanonicalizeCommand.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@
import com.google.devtools.common.options.OptionsProvider;
import java.util.Collection;
import java.util.List;
import java.util.logging.Level;

/** The 'blaze canonicalize-flags' command. */
@Command(
Expand Down Expand Up @@ -162,7 +163,7 @@ public ExitCode exec(CommandEnvironment env, OptionsProvider options) {
// Print out the canonical invocation policy if requested.
if (canonicalizeOptions.canonicalizePolicy) {
ImmutableList<FlagPolicy> effectiveFlagPolicies =
InvocationPolicyEnforcer.getEffectivePolicies(policy, parser, commandName);
InvocationPolicyEnforcer.getEffectivePolicies(policy, parser, commandName, Level.INFO);
InvocationPolicy effectivePolicy =
InvocationPolicy.newBuilder().addAllFlagPolicies(effectiveFlagPolicies).build();
env.getReporter().getOutErr().printOutLn(effectivePolicy.toString());
Expand Down
133 changes: 82 additions & 51 deletions src/main/java/com/google/devtools/common/options/InvocationPolicyEnforcer.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,9 +41,8 @@
import javax.annotation.Nullable;

/**
* Enforces the {@link FlagPolicy}s (from an {@link InvocationPolicy} proto) on an
* {@link OptionsParser} by validating and changing the flag values in the given
* {@link OptionsParser}.
* Enforces the {@link FlagPolicy}s (from an {@link InvocationPolicy} proto) on an {@link
* OptionsParser} by validating and changing the flag values in the given {@link OptionsParser}.
*
* <p>"Flag" and "Option" are used interchangeably in this file.
*/
Expand All @@ -55,6 +54,7 @@ public final class InvocationPolicyEnforcer {
private static final Function<OptionDefinition, String> INVOCATION_POLICY_SOURCE_FUNCTION =
o -> INVOCATION_POLICY_SOURCE;
@Nullable private final InvocationPolicy invocationPolicy;
private final Level loglevel;

/**
* Creates an InvocationPolicyEnforcer that enforces the given policy.
Expand All @@ -63,7 +63,20 @@ public final class InvocationPolicyEnforcer {
* nothing in calls to enforce().
*/
public InvocationPolicyEnforcer(@Nullable InvocationPolicy invocationPolicy) {
this(invocationPolicy, Level.FINE);
}

/**
* Creates an InvocationPolicyEnforcer that enforces the given policy.
*
* @param invocationPolicy the policy to enforce. A null policy means this enforcer will do
* nothing in calls to enforce().
* @param loglevel the level at which to log informational statements. Warnings and errors will
* still be logged at the appropriate level.
*/
public InvocationPolicyEnforcer(@Nullable InvocationPolicy invocationPolicy, Level loglevel) {
this.invocationPolicy = invocationPolicy;
this.loglevel = loglevel;
}

public InvocationPolicy getInvocationPolicy() {
Expand Down Expand Up @@ -97,7 +110,8 @@ public void enforce(OptionsParser parser, @Nullable String command)

// The effective policy returned is expanded, filtered for applicable commands, and cleaned of
// redundancies and conflicts.
List<FlagPolicy> effectivePolicies = getEffectivePolicies(invocationPolicy, parser, command);
List<FlagPolicy> effectivePolicies =
getEffectivePolicies(invocationPolicy, parser, command, loglevel);

for (FlagPolicy flagPolicy : effectivePolicies) {
String flagName = flagPolicy.getFlagName();
Expand All @@ -109,7 +123,8 @@ public void enforce(OptionsParser parser, @Nullable String command)
// This flag doesn't exist. We are deliberately lenient if the flag policy has a flag
// we don't know about. This is for better future proofing so that as new flags are added,
// new policies can use the new flags without worrying about older versions of Bazel.
logger.info(
logger.log(
loglevel,
String.format("Flag '%s' specified by invocation policy does not exist", flagName));
continue;
}
Expand All @@ -124,16 +139,19 @@ public void enforce(OptionsParser parser, @Nullable String command)

switch (flagPolicy.getOperationCase()) {
case SET_VALUE:
applySetValueOperation(parser, flagPolicy, valueDescription, optionDescription);
applySetValueOperation(parser, flagPolicy, valueDescription, optionDescription, loglevel);
break;

case USE_DEFAULT:
applyUseDefaultOperation(parser, "UseDefault", optionDescription.getOptionDefinition());
applyUseDefaultOperation(
parser, "UseDefault", optionDescription.getOptionDefinition(), loglevel);
break;

case ALLOW_VALUES:
AllowValues allowValues = flagPolicy.getAllowValues();
FilterValueOperation.ALLOW_VALUE_OPERATION.apply(
FilterValueOperation.AllowValueOperation allowValueOperation =
new FilterValueOperation.AllowValueOperation(loglevel);
allowValueOperation.apply(
parser,
allowValues.getAllowedValuesList(),
allowValues.hasNewValue() ? allowValues.getNewValue() : null,
Expand All @@ -144,7 +162,9 @@ public void enforce(OptionsParser parser, @Nullable String command)

case DISALLOW_VALUES:
DisallowValues disallowValues = flagPolicy.getDisallowValues();
FilterValueOperation.DISALLOW_VALUE_OPERATION.apply(
FilterValueOperation.DisallowValueOperation disallowValueOperation =
new FilterValueOperation.DisallowValueOperation(loglevel);
disallowValueOperation.apply(
parser,
disallowValues.getDisallowedValuesList(),
disallowValues.hasNewValue() ? disallowValues.getNewValue() : null,
Expand Down Expand Up @@ -188,7 +208,7 @@ private static boolean policyApplies(FlagPolicy policy, ImmutableSet<String> app
* <p>Expands any policies on expansion flags.
*/
public static ImmutableList<FlagPolicy> getEffectivePolicies(
InvocationPolicy invocationPolicy, OptionsParser parser, String command)
InvocationPolicy invocationPolicy, OptionsParser parser, String command, Level loglevel)
throws OptionsParsingException {
if (invocationPolicy == null) {
return ImmutableList.of();
Expand All @@ -206,7 +226,7 @@ public static ImmutableList<FlagPolicy> getEffectivePolicies(
// Only keep and expand policies that are applicable to the current command.
continue;
}
List<FlagPolicy> policies = expandPolicy(policy, parser);
List<FlagPolicy> policies = expandPolicy(policy, parser, loglevel);
expandedPolicies.addAll(policies);
}

Expand Down Expand Up @@ -312,8 +332,7 @@ private static ImmutableList<ParsedOptionDescription> getExpansionsFromFlagPolic
* <p>None of the flagPolicies returned should be on expansion flags.
*/
private static List<FlagPolicy> expandPolicy(
FlagPolicy originalPolicy,
OptionsParser parser)
FlagPolicy originalPolicy, OptionsParser parser, Level loglevel)
throws OptionsParsingException {
List<FlagPolicy> expandedPolicies = new ArrayList<>();

Expand All @@ -337,17 +356,16 @@ private static List<FlagPolicy> expandPolicy(
.build();
boolean isExpansion = originalOptionDescription.isExpansion();

if (!subflags.isEmpty() && logger.isLoggable(Level.FINE)) {
// Log the expansion. Since this is logged regardless of user provided command line, it is
// only really useful for understanding the invocation policy itself. Most of the time,
// invocation policy does not change, so this can be a log level fine.
if (!subflags.isEmpty() && logger.isLoggable(loglevel)) {
// Log the expansion. This is only really useful for understanding the invocation policy
// itself.
List<String> subflagNames = new ArrayList<>(subflags.size());
for (ParsedOptionDescription subflag : subflags) {
subflagNames.add("--" + subflag.getOptionDefinition().getOptionName());
}

logger.logp(
Level.FINE,
loglevel,
"InvocationPolicyEnforcer",
"expandPolicy",
String.format(
Expand All @@ -374,7 +392,7 @@ private static List<FlagPolicy> expandPolicy(
FlagPolicy subflagAsPolicy =
getSingleValueSubflagAsPolicy(currentSubflag, originalPolicy, isExpansion);
// In case any of the expanded flags are themselves expansions, recurse.
expandedPolicies.addAll(expandPolicy(subflagAsPolicy, parser));
expandedPolicies.addAll(expandPolicy(subflagAsPolicy, parser, loglevel));
}
}

Expand Down Expand Up @@ -503,11 +521,12 @@ private static FlagPolicy getSingleValueSubflagAsPolicy(
return subflagAsPolicy;
}

private static void logInApplySetValueOperation(String formattingString, Object... objects) {
private static void logInApplySetValueOperation(
Level loglevel, String formattingString, Object... objects) {
// Finding the caller here is relatively expensive and shows up in profiling, so provide it
// manually.
logger.logp(
Level.INFO,
loglevel,
"InvocationPolicyEnforcer",
"applySetValueOperation",
String.format(formattingString, objects));
Expand All @@ -517,7 +536,8 @@ private static void applySetValueOperation(
OptionsParser parser,
FlagPolicy flagPolicy,
OptionValueDescription valueDescription,
OptionDescription optionDescription)
OptionDescription optionDescription,
Level loglevel)
throws OptionsParsingException {
SetValue setValue = flagPolicy.getSetValue();
OptionDefinition optionDefinition = optionDescription.getOptionDefinition();
Expand All @@ -544,6 +564,7 @@ private static void applySetValueOperation(
// The user set the value for the flag but the flag policy is overridable, so keep the user's
// value.
logInApplySetValueOperation(
loglevel,
"Keeping value '%s' from source '%s' for flag '%s' "
+ "because the invocation policy specifying the value(s) '%s' is overridable",
valueDescription.getValue(),
Expand All @@ -561,11 +582,13 @@ private static void applySetValueOperation(
for (String flagValue : setValue.getFlagValueList()) {
if (valueDescription == null) {
logInApplySetValueOperation(
loglevel,
"Setting value for flag '%s' from invocation policy to '%s', overriding the "
+ "default value '%s'",
optionDefinition.getOptionName(), flagValue, optionDefinition.getDefaultValue());
} else {
logInApplySetValueOperation(
loglevel,
"Setting value for flag '%s' from invocation policy to '%s', overriding "
+ "value '%s' from '%s'",
optionDefinition.getOptionName(),
Expand All @@ -579,7 +602,7 @@ private static void applySetValueOperation(
}

private static void applyUseDefaultOperation(
OptionsParser parser, String policyType, OptionDefinition option)
OptionsParser parser, String policyType, OptionDefinition option, Level loglevel)
throws OptionsParsingException {
OptionValueDescription clearedValueDescription = parser.clearValue(option);
if (clearedValueDescription != null) {
Expand All @@ -593,7 +616,8 @@ private static void applyUseDefaultOperation(
if (desc != null) {
clearedFlagDefaultValue = desc.getOptionDefinition().getDefaultValue();
}
logger.info(
logger.log(
loglevel,
String.format(
"Using default value '%s' for flag '%s' as specified by %s invocation policy, "
+ "overriding original value '%s' from '%s'",
Expand All @@ -605,34 +629,40 @@ private static void applyUseDefaultOperation(
}
}

/**
* Checks the user's flag values against a filtering function.
*/
/** Checks the user's flag values against a filtering function. */
private abstract static class FilterValueOperation {

private static final FilterValueOperation ALLOW_VALUE_OPERATION =
new FilterValueOperation("Allow") {
@Override
boolean isFlagValueAllowed(Set<Object> convertedPolicyValues, Object value) {
return convertedPolicyValues.contains(value);
}
};

private static final FilterValueOperation DISALLOW_VALUE_OPERATION =
new FilterValueOperation("Disallow") {
@Override
boolean isFlagValueAllowed(Set<Object> convertedPolicyValues, Object value) {
// In a disallow operation, the values that the flag policy specifies are not allowed,
// so the value is allowed if the set of policy values does not contain the current
// flag value.
return !convertedPolicyValues.contains(value);
}
};
private static final class AllowValueOperation extends FilterValueOperation {
AllowValueOperation(Level loglevel) {
super("Allow", loglevel);
}

@Override
boolean isFlagValueAllowed(Set<Object> convertedPolicyValues, Object value) {
return convertedPolicyValues.contains(value);
}
}

private static final class DisallowValueOperation extends FilterValueOperation {
DisallowValueOperation(Level loglevel) {
super("Disalllow", loglevel);
}

@Override
boolean isFlagValueAllowed(Set<Object> convertedPolicyValues, Object value) {
// In a disallow operation, the values that the flag policy specifies are not allowed,
// so the value is allowed if the set of policy values does not contain the current
// flag value.
return !convertedPolicyValues.contains(value);
}
}

private final String policyType;
private final Level loglevel;

FilterValueOperation(String policyType) {
FilterValueOperation(String policyType, Level loglevel) {
this.policyType = policyType;
this.loglevel = loglevel;
}

/**
Expand Down Expand Up @@ -724,7 +754,8 @@ void checkDefaultValue(
convertedPolicyValues, optionDescription.getOptionDefinition().getDefaultValue())) {
if (newValue != null) {
// Use the default value from the policy.
logger.info(
logger.log(
loglevel,
String.format(
"Overriding default value '%s' for flag '%s' with value '%s' specified by "
+ "invocation policy. %sed values are: %s",
Expand Down Expand Up @@ -766,7 +797,7 @@ void checkUserValue(
for (Object value : optionValues) {
if (!isFlagValueAllowed(convertedPolicyValues, value)) {
if (useDefault) {
applyUseDefaultOperation(parser, policyType + "Values", option);
applyUseDefaultOperation(parser, policyType + "Values", option, loglevel);
} else {
throw new OptionsParsingException(
String.format(
Expand All @@ -781,7 +812,8 @@ void checkUserValue(

if (!isFlagValueAllowed(convertedPolicyValues, valueDescription.getValue())) {
if (newValue != null) {
logger.info(
logger.log(
loglevel,
String.format(
"Overriding disallowed value '%s' for flag '%s' with value '%s' "
+ "specified by invocation policy. %sed values are: %s",
Expand All @@ -793,7 +825,7 @@ void checkUserValue(
parser.clearValue(option);
setFlagValue(parser, option, newValue);
} else if (useDefault) {
applyUseDefaultOperation(parser, policyType + "Values", option);
applyUseDefaultOperation(parser, policyType + "Values", option, loglevel);
} else {
throw new OptionsParsingException(
String.format(
Expand All @@ -815,4 +847,3 @@ private static void setFlagValue(OptionsParser parser, OptionDefinition flag, St
ImmutableList.of(String.format("--%s=%s", flag.getOptionName(), flagValue)));
}
}

0 comments on commit 334d2f1

Please sign in to comment.