public async Task GetMetrics_HandlesExceptions()
{
// MessagingEntityNotFoundException
_mockMessagingProvider
.Setup(p => p.CreateBatchMessageReceiver(_entityPath, _testConnection))
.Throws(new ServiceBusException("", reason: ServiceBusFailureReason.MessagingEntityNotFound));
ServiceBusListener listener = new ServiceBusListener(_functionId, EntityType.Queue, _entityPath, false, _mockExecutor.Object, _serviceBusOptions,
_mockServiceBusAccount.Object, _mockMessagingProvider.Object, _loggerFactory, false);
var metrics = await((ServiceBusScaleMonitor)listener.GetMonitor()).GetMetricsAsync();
Assert.AreEqual(0, metrics.PartitionCount);
Assert.AreEqual(0, metrics.MessageCount);
Assert.AreEqual(TimeSpan.FromSeconds(0), metrics.QueueTime);
Assert.AreNotEqual(default(DateTime), metrics.Timestamp);
var warning = _loggerProvider.GetAllLogMessages().Single(p => p.Level == LogLevel.Warning);
Assert.AreEqual($"ServiceBus queue '{_entityPath}' was not found.", warning.FormattedMessage);
_loggerProvider.ClearAllLogMessages();
// UnauthorizedAccessException
_mockMessagingProvider
.Setup(p => p.CreateBatchMessageReceiver(_entityPath, _testConnection))
.Throws(new UnauthorizedAccessException(""));
listener = new ServiceBusListener(_functionId, EntityType.Queue, _entityPath, false, _mockExecutor.Object, _serviceBusOptions,
_mockServiceBusAccount.Object, _mockMessagingProvider.Object, _loggerFactory, false);
metrics = await((ServiceBusScaleMonitor)listener.GetMonitor()).GetMetricsAsync();
Assert.AreEqual(0, metrics.PartitionCount);
Assert.AreEqual(0, metrics.MessageCount);
Assert.AreEqual(TimeSpan.FromSeconds(0), metrics.QueueTime);
Assert.AreNotEqual(default(DateTime), metrics.Timestamp);
warning = _loggerProvider.GetAllLogMessages().Single(p => p.Level == LogLevel.Warning);
Assert.AreEqual($"Connection string does not have Manage claim for queue '{_entityPath}'. Failed to get queue description to derive queue length metrics. " +
$"Falling back to using first message enqueued time.",
warning.FormattedMessage);
_loggerProvider.ClearAllLogMessages();
// Generic Exception
_mockMessagingProvider
.Setup(p => p.CreateBatchMessageReceiver(_entityPath, _testConnection))
.Throws(new Exception("Uh oh"));
listener = new ServiceBusListener(_functionId, EntityType.Queue, _entityPath, false, _mockExecutor.Object, _serviceBusOptions,
_mockServiceBusAccount.Object, _mockMessagingProvider.Object, _loggerFactory, false);
metrics = await((ServiceBusScaleMonitor)listener.GetMonitor()).GetMetricsAsync();
Assert.AreEqual(0, metrics.PartitionCount);
Assert.AreEqual(0, metrics.MessageCount);
Assert.AreEqual(TimeSpan.FromSeconds(0), metrics.QueueTime);
Assert.AreNotEqual(default(DateTime), metrics.Timestamp);
warning = _loggerProvider.GetAllLogMessages().Single(p => p.Level == LogLevel.Warning);
Assert.AreEqual($"Error querying for Service Bus queue scale status: Uh oh", warning.FormattedMessage);
}
public async Task Starting_MultipleJobhostChannels_Succeeds()
{
_testLoggerProvider.ClearAllLogMessages();
int expectedProcessCount = 3;
RpcFunctionInvocationDispatcher functionDispatcher = GetTestFunctionDispatcher(expectedProcessCount);
await functionDispatcher.InitializeAsync(GetTestFunctionsList(RpcWorkerConstants.NodeLanguageWorkerName));
var finalChannelCount = await WaitForJobhostWorkerChannelsToStartup(functionDispatcher, expectedProcessCount);
Assert.Equal(expectedProcessCount, finalChannelCount);
VerifyStartIntervals(TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(15));
}
public async Task CreateTriggerMetrics_HandlesExceptions()
{
// StorageException
_mockBlobContainer
.Setup(c => c.GetBlobClient(IsAny <string>()))
.Throws(new RequestFailedException(404, "Uh oh"));
var partitionInfo = new List <PartitionProperties>
{
new TestPartitionProperties()
};
var metrics = await _scaleMonitor.CreateTriggerMetrics(partitionInfo, true);
Assert.AreEqual(1, metrics.PartitionCount);
Assert.AreEqual(0, metrics.EventCount);
Assert.AreNotEqual(default(DateTime), metrics.Timestamp);
var warning = _loggerProvider.GetAllLogMessages().Single(p => p.Level == Extensions.Logging.LogLevel.Warning);
var expectedWarning = $"Function '{_functionId}': Unable to deserialize partition or lease info with the following errors: " +
$"Checkpoint file data could not be found for blob on Partition: '0', EventHub: '{_eventHubName}', " +
$"'{_consumerGroup}'. Error: Uh oh";
Assert.AreEqual(expectedWarning, warning.FormattedMessage);
_loggerProvider.ClearAllLogMessages();
// Generic Exception
_mockBlobContainer
.Setup(c => c.GetBlobClient(IsAny <string>()))
.Throws(new Exception("Uh oh"));
partitionInfo = new List <PartitionProperties>
{
new TestPartitionProperties()
};
metrics = await _scaleMonitor.CreateTriggerMetrics(partitionInfo, true);
Assert.AreEqual(1, metrics.PartitionCount);
Assert.AreEqual(0, metrics.EventCount);
Assert.AreNotEqual(default(DateTime), metrics.Timestamp);
warning = _loggerProvider.GetAllLogMessages().Single(p => p.Level == Extensions.Logging.LogLevel.Warning);
expectedWarning = $"Function '{_functionId}': Unable to deserialize partition or lease info with the following errors: " +
$"Encountered exception while checking for last checkpointed sequence number for blob on Partition: '0', " +
$"EventHub: '{_eventHubName}', Consumer Group: '{_consumerGroup}'. Error: Uh oh";
Assert.AreEqual(expectedWarning, warning.FormattedMessage);
_loggerProvider.ClearAllLogMessages();
}
public async Task ListCheckpointsAsync_LogsOnInvalidCheckpoints()
{
var testLoggerProvider = new TestLoggerProvider();
Mock <BlobContainerClient> containerClientMock = new Mock <BlobContainerClient>(MockBehavior.Strict);
containerClientMock.Setup(c => c.GetBlobsAsync(It.IsAny <BlobTraits>(), It.IsAny <BlobStates>(), It.IsAny <string>(), It.IsAny <CancellationToken>()))
.Returns(AsyncPageable <BlobItem> .FromPages(new[]
{
Page <BlobItem> .FromValues(new[]
{
BlobsModelFactory.BlobItem("testnamespace/testeventhubname/testconsumergroup/checkpoint/0", false, BlobsModelFactory.BlobItemProperties(false), metadata: new Dictionary <string, string>())
}, null, Mock.Of <Response>())
}));
BlobsCheckpointStore store = new BlobsCheckpointStore(
containerClientMock.Object,
new BasicRetryPolicy(new EventHubsRetryOptions()),
_functionId,
testLoggerProvider.CreateLogger("TestLogger")
);
await store.ListCheckpointsAsync(_namespace, _eventHubName, _consumerGroup, CancellationToken.None);
var warning = testLoggerProvider.GetAllLogMessages().Single(p => p.Level == Extensions.Logging.LogLevel.Warning);
var expectedWarning = "Function 'EventHubsTriggerFunction': An invalid checkpoint was found for partition: '0' of " +
"FullyQualifiedNamespace: 'TestNamespace'; EventHubName: 'TestEventHubName'; ConsumerGroup: 'TestConsumerGroup'. " +
"This checkpoint is not valid and will be ignored.";
Assert.AreEqual(expectedWarning, warning.FormattedMessage);
testLoggerProvider.ClearAllLogMessages();
}
public async Task ValidateHostIdUsageAsync_ExistingHostIdInfoMatches_Succeeds()
{
await ClearHostIdInfoAsync();
HostIdValidator.HostIdInfo hostIdInfo = new HostIdValidator.HostIdInfo
{
Hostname = _testHostname
};
await _hostIdValidator.WriteHostIdAsync(_testHostId, hostIdInfo, _blobContainerClient);
_loggerProvider.ClearAllLogMessages();
await _hostIdValidator.ValidateHostIdUsageAsync(_testHostId);
var logs = _loggerProvider.GetAllLogMessages();
Assert.Empty(logs);
}
public async Task InvalidStorageConnection_Handled()
{
var configuration = new ConfigurationBuilder().Build();
Assert.Null(configuration.GetWebJobsConnectionString(ConnectionStringNames.Storage));
var options = new ScaleOptions();
ILoggerFactory loggerFactory = new LoggerFactory();
loggerFactory.AddProvider(_loggerProvider);
var localRepository = new TableStorageScaleMetricsRepository(configuration, _hostIdProviderMock.Object, new OptionsWrapper <ScaleOptions>(options), loggerFactory, new TestEnvironment());
var monitor1 = new TestScaleMonitor1();
var monitor2 = new TestScaleMonitor2();
var monitor3 = new TestScaleMonitor3();
var monitors = new IScaleMonitor[] { monitor1, monitor2, monitor3 };
var result = await localRepository.ReadMetricsAsync(monitors);
Assert.Empty(result);
var logs = _loggerProvider.GetAllLogMessages();
Assert.Single(logs);
Assert.Equal("Azure Storage connection string is empty or invalid. Unable to read/write scale metrics.", logs[0].FormattedMessage);
_loggerProvider.ClearAllLogMessages();
Dictionary <IScaleMonitor, ScaleMetrics> metricsMap = new Dictionary <IScaleMonitor, ScaleMetrics>();
metricsMap.Add(monitor1, new TestScaleMetrics1 {
Count = 10
});
metricsMap.Add(monitor2, new TestScaleMetrics2 {
Num = 50
});
metricsMap.Add(monitor3, new TestScaleMetrics3 {
Length = 100
});
await localRepository.WriteMetricsAsync(metricsMap);
}
public async Task StartAssignment_AppliesAssignmentContext()
{
var envValue = new
{
Name = Path.GetTempFileName().Replace(".", string.Empty),
Value = Guid.NewGuid().ToString()
};
_settingsManager.SetSetting(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "1");
WebScriptHostManager.ResetStandbyMode();
var context = new HostAssignmentContext
{
Environment = new Dictionary <string, string>
{
{ envValue.Name, envValue.Value }
}
};
bool result = _instanceManager.StartAssignment(context);
Assert.True(result);
Assert.True(WebScriptHostManager.InStandbyMode);
// specialization is done in the background
await Task.Delay(500);
var value = Environment.GetEnvironmentVariable(envValue.Name);
Assert.Equal(value, envValue.Value);
// verify logs
var logs = _loggerProvider.GetAllLogMessages().Select(p => p.FormattedMessage).ToArray();
Assert.Collection(logs,
p => Assert.StartsWith("Starting Assignment", p),
p => Assert.StartsWith("Applying 1 app setting(s)", p),
p => Assert.StartsWith("Triggering specialization", p));
// calling again should return false, since we're no longer
// in placeholder mode
_loggerProvider.ClearAllLogMessages();
result = _instanceManager.StartAssignment(context);
Assert.False(result);
logs = _loggerProvider.GetAllLogMessages().Select(p => p.FormattedMessage).ToArray();
Assert.Collection(logs,
p => Assert.StartsWith("Assign called while host is not in placeholder mode", p));
}
public void Synchronize_UpdatesValue()
{
_mockEnvironment.Setup(p => p.GetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteHostName)).Returns((string)null);
_mockEnvironment.Setup(p => p.GetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteName)).Returns((string)null);
Assert.Equal(null, _hostNameProvider.Value);
// no header present
HttpRequest request = new DefaultHttpContext().Request;
_hostNameProvider.Synchronize(request, _logger);
Assert.Equal(null, _hostNameProvider.Value);
// empty header value
request = new DefaultHttpContext().Request;
request.Headers.Add(ScriptConstants.AntaresDefaultHostNameHeader, string.Empty);
_hostNameProvider.Synchronize(request, _logger);
Assert.Equal(null, _hostNameProvider.Value);
// host provided via header - expect update
request = new DefaultHttpContext().Request;
request.Headers.Add(ScriptConstants.AntaresDefaultHostNameHeader, "test.azurewebsites.net");
_hostNameProvider.Synchronize(request, _logger);
Assert.Equal("test.azurewebsites.net", _hostNameProvider.Value);
var logs = _loggerProvider.GetAllLogMessages();
Assert.Equal(1, logs.Count);
Assert.Equal("HostName updated from '(null)' to 'test.azurewebsites.net'", logs[0].FormattedMessage);
// no change in header value - no update expected
_loggerProvider.ClearAllLogMessages();
_hostNameProvider.Synchronize(request, _logger);
Assert.Equal("test.azurewebsites.net", _hostNameProvider.Value);
Assert.Equal("test.azurewebsites.net", _hostNameProvider.Value);
logs = _loggerProvider.GetAllLogMessages();
Assert.Equal(0, logs.Count);
// another change - expect update
request = new DefaultHttpContext().Request;
request.Headers.Add(ScriptConstants.AntaresDefaultHostNameHeader, "test2.azurewebsites.net");
_hostNameProvider.Synchronize(request, _logger);
Assert.Equal("test2.azurewebsites.net", _hostNameProvider.Value);
logs = _loggerProvider.GetAllLogMessages();
Assert.Equal(1, logs.Count);
Assert.Equal("HostName updated from 'test.azurewebsites.net' to 'test2.azurewebsites.net'", logs[0].FormattedMessage);
}
public LinuxContainerMetricsPublisherTests()
{
var handlerMock = new Mock <HttpMessageHandler>(MockBehavior.Strict);
handlerMock.Protected().Setup <Task <HttpResponseMessage> >("SendAsync",
ItExpr.IsAny <HttpRequestMessage>(),
ItExpr.IsAny <CancellationToken>())
.Callback <HttpRequestMessage, CancellationToken>((request, token) => ValidateRequest(request))
.ReturnsAsync(new HttpResponseMessage
{
StatusCode = HttpStatusCode.OK
});
_httpClient = new HttpClient(handlerMock.Object);
var mockEnvironment = new Mock <IEnvironment>(MockBehavior.Strict);
mockEnvironment.Setup(p => p.GetEnvironmentVariable(EnvironmentSettingNames.ContainerName)).Returns(_containerName);
mockEnvironment.Setup(p => p.GetEnvironmentVariable(EnvironmentSettingNames.LinuxNodeIpAddress)).Returns(_testIpAddress);
mockEnvironment.Setup(p => p.GetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteHostName)).Returns(_testHostName);
mockEnvironment.Setup(p => p.GetEnvironmentVariable(EnvironmentSettingNames.WebSiteHomeStampName)).Returns(_testStampName);
mockEnvironment.Setup(p => p.GetEnvironmentVariable(EnvironmentSettingNames.WebSiteStampDeploymentId)).Returns(_testTenant);
var websiteAuthEncryptionKey = TestHelpers.GenerateKeyBytes();
var websiteAuthEncryptionStringKey = TestHelpers.GenerateKeyHexString(websiteAuthEncryptionKey);
Environment.SetEnvironmentVariable(EnvironmentSettingNames.WebSiteAuthEncryptionKey, websiteAuthEncryptionStringKey);
_testLoggerProvider = new TestLoggerProvider();
var loggerFactory = new LoggerFactory();
loggerFactory.AddProvider(_testLoggerProvider);
ILogger <LinuxContainerMetricsPublisher> logger = loggerFactory.CreateLogger <LinuxContainerMetricsPublisher>();
var hostNameProvider = new HostNameProvider(mockEnvironment.Object);
var standbyOptions = new TestOptionsMonitor <StandbyOptions>(new StandbyOptions {
InStandbyMode = true
});
_metricsPublisher = new LinuxContainerMetricsPublisher(mockEnvironment.Object, standbyOptions, logger, hostNameProvider, _httpClient);
_testLoggerProvider.ClearAllLogMessages();
}
public void StopAsync_LogListenerDetails()
{
try
{
Assert.DoesNotThrow(() => _listener.StopAsync(CancellationToken.None));
Assert.NotNull(_loggerProvider.GetAllLogMessages()
.SingleOrDefault(x => x.FormattedMessage.StartsWith("Attempting to stop ServiceBus listener")));
Assert.NotNull(_loggerProvider.GetAllLogMessages()
.SingleOrDefault(x => x.FormattedMessage.StartsWith("ServiceBus listener stopped")));
}
finally
{
_loggerProvider.ClearAllLogMessages();
}
}
public void PublishFunctionActivity_SendsRequestHeaders()
{
_metricsPublisher.Initialize();
_metricsPublisher.AddFunctionExecutionActivity(
_testFunctionActivity.FunctionName,
_testFunctionActivity.InvocationId,
_testFunctionActivity.Concurrency,
_testFunctionActivity.ExecutionStage,
_testFunctionActivity.IsSucceeded,
_testFunctionActivity.ExecutionTimeSpanInMs,
_testFunctionActivity.EventTimeStamp);
Assert.Matches("Added function activity", _testLoggerProvider.GetAllLogMessages().Single().FormattedMessage);
Assert.Equal(LogLevel.Debug, _testLoggerProvider.GetAllLogMessages().Single().Level);
_testLoggerProvider.ClearAllLogMessages();
_metricsPublisher.OnFunctionMetricsPublishTimer(null);
_metricsPublisher.OnFunctionMetricsPublishTimer(null);
Assert.Empty(_testLoggerProvider.GetAllLogMessages());
}
public void PublishFunctionActivity_SendsRequestHeaders()
{
_metricsPublisher.Initialize();
_metricsPublisher.AddFunctionExecutionActivity(
_testFunctionActivity.FunctionName,
_testFunctionActivity.InvocationId,
_testFunctionActivity.Concurrency,
_testFunctionActivity.ExecutionStage.ToString(),
_testFunctionActivity.IsSucceeded,
_testFunctionActivity.ExecutionTimeSpanInMs,
_testFunctionActivity.ExecutionId,
_testFunctionActivity.EventTimeStamp,
_testFunctionActivity.StartTime);
Assert.Empty(_testLoggerProvider.GetAllLogMessages());
_testLoggerProvider.ClearAllLogMessages();
_metricsPublisher.OnFunctionMetricsPublishTimer(null);
_metricsPublisher.OnFunctionMetricsPublishTimer(null);
Assert.Empty(_testLoggerProvider.GetAllLogMessages());
}
public void GetCheckpointsAsync_LogsOnRequestErrors()
{
var testLoggerProvider = new TestLoggerProvider();
Mock <BlobContainerClient> containerClientMock = new Mock <BlobContainerClient>(MockBehavior.Strict);
containerClientMock.Setup(c => c.GetBlobClient(It.IsAny <string>()))
.Throws(new RequestFailedException("Uh oh"));
BlobCheckpointStoreInternal store = new BlobCheckpointStoreInternal(
containerClientMock.Object,
_functionId,
testLoggerProvider.CreateLogger("TestLogger")
);
Assert.ThrowsAsync <RequestFailedException>(async() => await store.GetCheckpointAsync(_namespace, _eventHubName, _consumerGroup, _partitionId, CancellationToken.None));
var warning = testLoggerProvider.GetAllLogMessages().Single(p => p.Level == LogLevel.Warning);
var expectedWarning = "Function 'EventHubsTriggerFunction': An exception occurred when retrieving a checkpoint for " +
"FullyQualifiedNamespace: 'TestNamespace'; EventHubName: 'TestEventHubName'; ConsumerGroup: 'TestConsumerGroup'; PartitionId: '0'.";
Assert.AreEqual(expectedWarning, warning.FormattedMessage);
testLoggerProvider.ClearAllLogMessages();
}
public async Task CreateTriggerMetrics_HandlesExceptions()
{
// StorageException
_mockCheckpointStore
.Setup(c => c.GetCheckpointAsync(It.IsAny <string>(), It.IsAny <string>(), It.IsAny <string>(), It.IsAny <string>(), It.IsAny <CancellationToken>()))
.ThrowsAsync(new RequestFailedException(404, "Uh oh"));
_partitions = new List <PartitionProperties>
{
new TestPartitionProperties()
};
var metrics = await _scaleMonitor.GetMetricsAsync();
Assert.AreEqual(1, metrics.PartitionCount);
Assert.AreEqual(0, metrics.EventCount);
Assert.AreNotEqual(default(DateTime), metrics.Timestamp);
// Generic Exception
_mockCheckpointStore
.Setup(c => c.GetCheckpointAsync(It.IsAny <string>(), It.IsAny <string>(), It.IsAny <string>(), It.IsAny <string>(), It.IsAny <CancellationToken>()))
.ThrowsAsync(new Exception("Uh oh"));
_partitions = new List <PartitionProperties>
{
new TestPartitionProperties()
};
metrics = await _scaleMonitor.GetMetricsAsync();
Assert.AreEqual(1, metrics.PartitionCount);
Assert.AreEqual(0, metrics.EventCount);
Assert.AreNotEqual(default(DateTime), metrics.Timestamp);
_loggerProvider.ClearAllLogMessages();
}
public void ListCheckpointsAsync_LogsOnRequestErrors()
{
var testLoggerProvider = new TestLoggerProvider();
Mock <BlobContainerClient> containerClientMock = new Mock <BlobContainerClient>(MockBehavior.Strict);
containerClientMock.Setup(c => c.GetBlobsAsync(It.IsAny <BlobTraits>(), It.IsAny <BlobStates>(), It.IsAny <string>(), It.IsAny <CancellationToken>()))
.Throws(new RequestFailedException("Uh oh"));
BlobsCheckpointStore store = new BlobsCheckpointStore(
containerClientMock.Object,
new BasicRetryPolicy(new EventHubsRetryOptions()),
_functionId,
testLoggerProvider.CreateLogger("TestLogger")
);
Assert.ThrowsAsync <RequestFailedException>(async() => await store.ListCheckpointsAsync(_namespace, _eventHubName, _consumerGroup, CancellationToken.None));
var warning = testLoggerProvider.GetAllLogMessages().Single(p => p.Level == Extensions.Logging.LogLevel.Warning);
var expectedWarning = "Function 'EventHubsTriggerFunction': An exception occurred when listing checkpoints for " +
"FullyQualifiedNamespace: 'TestNamespace'; EventHubName: 'TestEventHubName'; ConsumerGroup: 'TestConsumerGroup'.";
Assert.AreEqual(expectedWarning, warning.FormattedMessage);
testLoggerProvider.ClearAllLogMessages();
}
public void ClearLogMessages() => _loggerProvider.ClearAllLogMessages();