Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix(logs): Added and refactored audience and feature variable evaluation logs #229

Merged
merged 15 commits into from
Jul 27, 2020
Merged

Large diffs are not rendered by default.

15 changes: 8 additions & 7 deletions OptimizelySDK.Tests/DecisionServiceTest.cs
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/**
*
* Copyright 2017-2019, Optimizely and contributors
* Copyright 2017-2020, Optimizely and contributors
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
Expand Down Expand Up @@ -697,8 +697,8 @@ public void TestGetVariationForFeatureRolloutWhenUserDoesNotQualifyForAnyTargeti

Assert.IsTrue(TestData.CompareObjects(expectedDecision, actualDecision));

LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, $"User \"user_1\" does not meet the conditions to be in rollout rule for audience \"{ProjectConfig.AudienceIdMap[experiment0.AudienceIds[0]].Name}\"."));
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, $"User \"user_1\" does not meet the conditions to be in rollout rule for audience \"{ProjectConfig.AudienceIdMap[experiment1.AudienceIds[0]].Name}\"."));
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, $"User \"user_1\" does not meet the conditions for targeting rule \"1\"."));
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, $"User \"user_1\" does not meet the conditions for targeting rule \"2\"."));
}

[Test]
Expand Down Expand Up @@ -785,10 +785,11 @@ public void TestGetVariationForFeatureRolloutCheckAudienceInEveryoneElseRule()
actualDecision = decisionService.GetVariationForFeatureRollout(featureFlag, GenericUserId, null, ProjectConfig);
Assert.Null(actualDecision);

LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"testUser1\" does not meet the conditions to be in rollout rule for audience \"Chrome users\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"testUser1\" does not meet the conditions to be in rollout rule for audience \"iPhone users in San Francisco\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"genericUserId\" does not meet the conditions to be in rollout rule for audience \"Chrome users\"."), Times.Exactly(2));
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"genericUserId\" does not meet the conditions to be in rollout rule for audience \"iPhone users in San Francisco\"."), Times.Exactly(3));
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"testUser1\" does not meet the conditions for targeting rule \"1\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"testUser1\" does not meet the conditions for targeting rule \"2\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"genericUserId\" does not meet the conditions for targeting rule \"1\"."), Times.Exactly(2));
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"genericUserId\" does not meet the conditions for targeting rule \"2\"."), Times.Exactly(2));
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"genericUserId\" does not meet the conditions for targeting rule \"3\"."), Times.Exactly(1));
}

#endregion // GetVariationForFeatureRollout Tests
Expand Down
34 changes: 17 additions & 17 deletions OptimizelySDK.Tests/OptimizelyTest.cs
Original file line number Diff line number Diff line change
Expand Up @@ -1440,7 +1440,7 @@ public void TestGetFeatureVariableDoubleReturnsRightValueWhenUserBuckedIntoFeatu
var variableValue = (double)optly.Invoke("GetFeatureVariableDouble", featureKey, variableKey, TestUserId, null);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Returning variable value ""{variableValue}"" for variation ""{variation.Key}"" of feature flag ""{featureKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Got variable value ""{variableValue}"" for variable ""{variableKey}"" of feature flag ""{featureKey}""."));
}

[Test]
Expand Down Expand Up @@ -1469,7 +1469,7 @@ public void TestGetFeatureVariableIntegerReturnsRightValueWhenUserBuckedIntoFeat
var variableValue = (int)optly.Invoke("GetFeatureVariableInteger", featureKey, variableKey, TestUserId, userAttributes);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Returning variable value ""{variableValue}"" for variation ""{variation.Key}"" of feature flag ""{featureKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Got variable value ""{variableValue}"" for variable ""{variableKey}"" of feature flag ""{featureKey}""."));
}

[Test]
Expand All @@ -1492,7 +1492,7 @@ public void TestGetFeatureVariableDoubleReturnsDefaultValueWhenUserBuckedIntoFea
var variableValue = (double)optly.Invoke("GetFeatureVariableDouble", featureKey, variableKey, TestUserId, null);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning default value for variable ""{variableKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning the default variable value ""{variableValue}""."));
}

[Test]
Expand Down Expand Up @@ -1521,7 +1521,7 @@ public void TestGetFeatureVariableIntegerReturnsDefaultValueWhenUserBuckedIntoFe
var variableValue = (int)optly.Invoke("GetFeatureVariableInteger", featureKey, variableKey, TestUserId, userAttributes);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning default value for variable ""{variableKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning the default variable value ""{variableValue}""."));
}

[Test]
Expand All @@ -1543,7 +1543,7 @@ public void TestGetFeatureVariableBooleanReturnsRightValueWhenUserBuckedIntoRoll
var variableValue = (bool)optly.Invoke("GetFeatureVariableBoolean", featureKey, variableKey, TestUserId, null);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Returning variable value ""true"" for variation ""{variation.Key}"" of feature flag ""{featureKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Got variable value ""true"" for variable ""{variableKey}"" of feature flag ""{featureKey}""."));
}

[Test]
Expand Down Expand Up @@ -1575,7 +1575,7 @@ public void TestGetFeatureVariableJSONReturnsRightValueWhenUserBucketIntoRollout
Assert.AreEqual(expectedIntValue, variableValue.GetValue<long>("int_var"));
Assert.AreEqual(expectedStringValue, variableValue.GetValue<string>("string_var"));

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Returning variable value ""{variableValue}"" for variation ""{variation.Key}"" of feature flag ""{featureKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Got variable value ""{variableValue}"" for variable ""{variableKey}"" of feature flag ""{featureKey}""."));
}

[Test]
Expand Down Expand Up @@ -1607,7 +1607,7 @@ public void TestGetFeatureVariableJSONReturnsRightValueWhenUserBucketIntoRollout
Assert.AreEqual(expectedIntValue, variableValue.GetValue<long>("int_var"));
Assert.AreEqual(expectedStringValue, variableValue.GetValue<string>("string_var"));

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Returning variable value ""{variableValue}"" for variation ""{variation.Key}"" of feature flag ""{featureKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Got variable value ""{variableValue}"" for variable ""{variableKey}"" of feature flag ""{featureKey}""."));
}

[Test]
Expand Down Expand Up @@ -1637,7 +1637,7 @@ public void TestGetFeatureVariableStringReturnsRightValueWhenUserBuckedIntoRollo
var variableValue = (string)optly.Invoke("GetFeatureVariableString", featureKey, variableKey, TestUserId, userAttributes);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Returning variable value ""{variableValue}"" for variation ""{variation.Key}"" of feature flag ""{featureKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Got variable value ""{variableValue}"" for variable ""{variableKey}"" of feature flag ""{featureKey}""."));
}

[Test]
Expand All @@ -1658,8 +1658,7 @@ public void TestGetFeatureVariableBooleanReturnsDefaultValueWhenUserBuckedIntoRo
optly.SetFieldOrProperty("ProjectConfigManager", ConfigManager);
var variableValue = (bool)optly.Invoke("GetFeatureVariableBoolean", featureKey, variableKey, TestUserId, null);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning default value for variable ""{variableKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning the default variable value ""true""."));
}

[Test]
Expand Down Expand Up @@ -1688,7 +1687,7 @@ public void TestGetFeatureVariableStringReturnsDefaultValueWhenUserBuckedIntoRol
var variableValue = (string)optly.Invoke("GetFeatureVariableString", featureKey, variableKey, TestUserId, userAttributes);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning default value for variable ""{variableKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning the default variable value ""{variableValue}""."));
}

[Test]
Expand Down Expand Up @@ -1820,7 +1819,7 @@ public void TestGetFeatureVariableValueForTypeGivenFeatureFlagIsNotEnabledForUse
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO,
$@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning default value for variable ""{variableKey}""."));
$@"Feature ""{featureKey}"" is not enabled for user {TestUserId}. Returning the default variable value ""{variableValue}""."));
}

// Should return default value and log message when feature is enabled for the user
Expand Down Expand Up @@ -1876,10 +1875,9 @@ public void TestGetFeatureVariableValueForTypeGivenFeatureFlagIsEnabledForUserAn
var variableValue = (double?)optly.InvokeGeneric("GetFeatureVariableValueForType", new Type[] { typeof(double?) }, featureKey, variableKey, TestUserId, null, variableType);
Assert.AreEqual(expectedValue, variableValue);

LoggerMock.Verify(l => l.Log(LogLevel.INFO,
$@"Returning variable value ""{variableValue}"" for variation ""{variation.Key}"" of feature flag ""{featureKey}""."));
LoggerMock.Verify(l => l.Log(LogLevel.INFO, $@"Got variable value ""{variableValue}"" for variable ""{variableKey}"" of feature flag ""{featureKey}""."));
}

// Verify that GetFeatureVariableValueForType returns correct variable value for rollout rule.
[Test]
public void TestGetFeatureVariableValueForTypeWithRolloutRule()
Expand Down Expand Up @@ -2082,8 +2080,8 @@ public void TestIsFeatureEnabledGivenVariationNotFoundInFeatureExperimentButInRo
Assert.True(Optimizely.IsFeatureEnabled(featureKey, TestUserId, userAttributes));

LoggerMock.Verify(l => l.Log(LogLevel.INFO, "The feature flag \"boolean_single_variable_feature\" is not used in any experiments."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"testUserId\" does not meet the conditions to be in rollout rule for audience \"Chrome users\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"testUserId\" does not meet the conditions to be in rollout rule for audience \"iPhone users in San Francisco\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"testUserId\" does not meet the conditions for targeting rule \"1\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "User \"testUserId\" does not meet the conditions for targeting rule \"2\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.DEBUG, "Assigned bucket [8408] to user [testUserId] with bucketing ID [testUserId]."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.INFO, "The user \"testUserId\" is bucketed into a rollout for feature flag \"boolean_single_variable_feature\"."), Times.Once);
LoggerMock.Verify(l => l.Log(LogLevel.INFO, "The user \"testUserId\" is not being experimented on feature \"boolean_single_variable_feature\"."), Times.Once);
Expand Down Expand Up @@ -3318,6 +3316,7 @@ public void TestGetAllFeatureVariablesRollout()

var result = (OptimizelyJSON)optly.Invoke("GetAllFeatureVariables", featureKey, TestUserId, userAttributes);
Assert.NotNull(result);
LoggerMock.Verify(log => log.Log(LogLevel.INFO, "Feature \"" + featureKey + "\" is not enabled for user \"" + TestUserId + "\""), Times.Once);

LoggerMock.Verify(log => log.Log(LogLevel.INFO, "User \"" + TestUserId + "\" was not bucketed into any variation for feature flag \"" + featureKey + "\". " +
"The default values are being returned."), Times.Once);
Expand All @@ -3335,6 +3334,7 @@ public void TestGetAllFeatureVariablesSourceFeatureTest()

var variableValues = optimizely.GetAllFeatureVariables(featureKey, TestUserId, null);
Assert.IsTrue(TestData.CompareObjects(variableValues.ToDictionary(), expectedValue));
LoggerMock.Verify(log => log.Log(LogLevel.INFO, "Feature \"" + featureKey + "\" is enabled for user \"" + TestUserId + "\""), Times.Once);

LoggerMock.Verify(log => log.Log(LogLevel.INFO, "User \"" + TestUserId + "\" was not bucketed into any variation for feature flag \"" + featureKey + "\". " +
"The default values are being returned."), Times.Never);
Expand Down
Loading