public void Start()
{
var moduleCount = 0;
foreach (var module in _modules)
{
var name = module.GetType().Name;
using (_logger.AddContext("Module", name))
{
try
{
_logger.Debug($"Starting {name}");
if (module.Start())
{
moduleCount++;
}
}
catch (Exception e)
{
_logger.Error("Error occured while starting module", e);
}
}
}
_logger.Debug("{ModuleCount} of {ModuleTotal} module(s) started sucesfully", moduleCount, _modules.Count());
_logger.Information("ServiceHost Started");
}
public async Task Reset(int newGameweek)
{
using var scope = _logger.AddContext("StateInit");
_logger.LogInformation($"Running reset for gw {newGameweek}");
_currentGameweekFixtures = await _fixtureClient.GetFixturesByGameweek(newGameweek);
var settings = await _settingsClient.GetGlobalSettings();
_players = settings.Players;
_teams = settings.Teams;
}
public Task Handle(GameweekMonitoringStarted notification, CancellationToken cancellationToken)
{
var initId = notification.CurrentGameweek.Id;
if (notification.CurrentGameweek.IsFinished)
{
initId++;
}
using var scope = _logger.AddContext(Tuple.Create(nameof(GameweekMonitoringStarted), initId.ToString()));
_logger.LogInformation("Init {Gameweek}", initId);
return(_matchState.Reset(initId));
}
private async static IAsyncEnumerable <CollectionPlan> GetCollectionPlansAsync(
IImmutableList <CollectionBackupPlan> collectionBackupPlans,
TechnicalConstants technicalConstants,
ICosmosAccountFacade cosmosFacade,
IStorageFacade storageFacade,
ILogger logger)
{
var byDbs = collectionBackupPlans.GroupBy(p => p.Db).ToDictionary(g => g.Key);
var dbs = await cosmosFacade.GetDatabasesAsync();
logger = logger.AddContext("Account", cosmosFacade.AccountName);
foreach (var db in dbs)
{
if (byDbs.ContainsKey(db.DatabaseName))
{
var byCollections = byDbs[db.DatabaseName].ToDictionary(c => c.Collection);
var collections = await db.GetCollectionsAsync();
foreach (var coll in collections)
{
if (byCollections.ContainsKey(coll.CollectionName))
{
var plan = byCollections[coll.CollectionName].SpecificPlan;
var collectionLogger = logger
.AddContext("Db", db.DatabaseName)
.AddContext("Collection", coll.CollectionName);
var logController = new LogCollectionBackupController(
coll,
storageFacade,
plan.Rpo,
plan.Included,
technicalConstants.LogConstants,
collectionLogger);
yield return(new CollectionPlan(
logController,
coll,
() => new IndexCollectionController(
coll.Parent.Parent.AccountName,
coll.Parent.DatabaseName,
coll.CollectionName,
storageFacade,
plan.RetentionInDays,
technicalConstants.IndexConstants,
collectionLogger),
plan));
}
}
}
}
}
public async Task <LogBatchResult> LogBatchAsync()
{
_logger.Display(
$"Backup {_collection.Parent.DatabaseName}.{_collection.CollectionName}...");
_logger.WriteEvent("Backup-Collection-Start");
var previousTimeStamp = _logFile.LastTimeStamp;
var timeWindow = await _collection.SizeTimeWindowAsync(
previousTimeStamp,
_logConstants.MaxBatchSize);
_logger
.AddContext("CurrentTimeStamp", timeWindow.currentTimeStamp)
.AddContext("DocumentCount", timeWindow.count)
.AddContext("MaxTimeStamp", timeWindow.maxTimeStamp)
.WriteEvent("LogBatchTimeWindow");
if (timeWindow.count != 0)
{
await LogDocumentBatchAsync(previousTimeStamp, timeWindow.maxTimeStamp);
}
else
{
_logger.Display("No document to backup");
_logger.WriteEvent("No-document-to-backup");
}
var hasCaughtUp = timeWindow.currentTimeStamp == timeWindow.maxTimeStamp;
var delta = TimeSpan.FromSeconds(
timeWindow.currentTimeStamp
- _logFile.LastCheckpointTimeStamp);
var isCheckpoint = delta >= _rpo;
if (hasCaughtUp && isCheckpoint)
{
await LogCheckPointAsync(timeWindow.currentTimeStamp);
}
await _logFile.PersistAsync();
var needDocumentsPurge = _logFile.TotalDocumentBlockCount > _logConstants.MaxBlockCount ||
_logFile.TotalDocumentSize > _logConstants.MaxDocumentSize;
var checkPointAge = _logFile.GetOldestCheckpointAge(timeWindow.currentTimeStamp);
var needCheckpointPurge =
_logFile.TotalCheckPointBlockCount > _logConstants.MaxBlockCount ||
_logFile.TotalCheckPointSize > _logConstants.MaxDocumentSize ||
checkPointAge > _logConstants.MaxCheckpointAge;
_logger.WriteEvent("Backup-Collection-End");
return(new LogBatchResult(hasCaughtUp, needDocumentsPurge, needCheckpointPurge));
}
public async Task <BlobLease?> AcquireLeaseAsync(string blobName, TimeSpan timeout)
{
var watch = new Stopwatch();
var waitTime = TimeSpan.FromSeconds(1);
watch.Start();
while (watch.Elapsed < timeout)
{
var lease = await _storageFacade.AcquireLeaseAsync(blobName);
if (lease != null)
{
return(lease);
}
else
{
waitTime = Min(timeout - watch.Elapsed, waitTime);
_logger.Display($"Blob {blobName} is locked for {watch.Elapsed}"
+ $", retry in {waitTime}");
_logger
.AddContext("duration", watch.Elapsed)
.WriteEvent("blob-locked");
await Task.Delay(waitTime);
waitTime = Min(waitTime * 2, TimeSpan.FromSeconds(5));
}
}
_logger.Display($"Blob {blobName} is locked, timeout expired");
return(null);
}
public async Task Process(CancellationToken token)
{
using var scope = _logger.BeginCorrelationScope();
using var scope2 = _logger.AddContext("MatchdaystatusCheck");
_logger.LogInformation($"Running {nameof(MatchDayStatusRecurringAction)}");
await _monitor.EveryFiveMinutesTick(token);
}
public async Task Process(CancellationToken token)
{
using var scope = _logger.BeginCorrelationScope();
using var scope2 = _logger.AddContext("NeardeadlineCheck");
_logger.LogInformation($"Running {nameof(NearDeadlineRecurringAction)}");
await _monitor.EveryMinuteTick();
}
private async Task ExecuteAsync(CancellationToken cancellationToken)
{
while (!cancellationToken.IsCancellationRequested)
{
if (_scheduler.IsStarted)
{
continue;
}
var jobCount = 0;
try
{
await _scheduler.Start();
foreach (var job in _jobs)
{
using (_logger.AddContext("JobId", job.Id))
{
if (await _scheduler.CheckExists(new JobKey(job.Id)))
{
continue;
}
var triggerOkorFail = _factory.Create(job.Id, job.GroupId);
if (!triggerOkorFail.Success)
{
_logger.Warn(string.Join(" ", triggerOkorFail.Error));
continue;
}
IJobDetail dtl = JobBuilder.Create(job.GetType())
.WithIdentity(job.Id, job.GroupId)
.WithDescription(job.Description)
.Build();
_logger.Verbose($"Scheduling job: {job.Id}");
await _scheduler.ScheduleJob(dtl, triggerOkorFail.Value);
jobCount++;
}
}
_logger.Information("{JobCount} of {JobTotal} job(s) scheduled successfully", jobCount, _jobs.Count());
}
catch (Exception e)
{
_logger.Error(e);
}
}
if (cancellationToken.IsCancellationRequested)
{
if (!_scheduler.IsShutdown)
{
await _scheduler.Shutdown(waitForJobsToComplete : true);
}
}
}
public DatabaseFacade(
Database database,
CosmosAccountFacade parent,
ILogger logger)
{
_database = database;
_parent = parent;
_logger = logger.AddContext("database", database.Id);
}
public CollectionFacade(
Container container,
string partitionPath,
IDatabaseFacade parent,
ILogger logger)
{
_container = container;
_partitionPath = partitionPath;
_parent = parent;
_logger = logger.AddContext("collection", container.Id);
}
private async Task CheckForRemovedFixtures(ICollection <Fixture> updatedFixtures, int gw)
{
using var scope = _logger.AddContext("CheckForRemovedFixtures");
var currentEvent = _currentFixtures.First().Event;
var updatedEvent = updatedFixtures.First().Event;
if (updatedEvent != currentEvent)
{
_logger.LogWarning("Checking fixtures for different gameweek. {Current} vs {Updated}. Aborting.", currentEvent, updatedEvent);
return;
}
foreach (var currentFixture in _currentFixtures)
{
try
{
var isFixtureRemoved = updatedFixtures.All(f => f.Id != currentFixture.Id);
if (isFixtureRemoved)
{
var settings = await _globalSettingsClient.GetGlobalSettings();
var teams = settings.Teams;
var homeTeam = teams.First(t => t.Id == currentFixture.HomeTeamId);
var awayTeam = teams.First(t => t.Id == currentFixture.AwayTeamId);
var removedFixture = new RemovedFixture(currentFixture.Id,
new (homeTeam.Id, homeTeam.Name, homeTeam.ShortName),
new (awayTeam.Id, awayTeam.Name, awayTeam.ShortName));
await _session.Publish(new FixtureRemovedFromGameweek(gw, removedFixture));
}
else
{
_logger.LogDebug("Fixture {FixtureId} not removed", currentFixture.Id);
}
}
catch (Exception e) when(LogError(e))
{
}
}
}
public CosmosAccountFacade(string accountName, string key, ILogger logger)
{
var options = new CosmosClientOptions
{
AllowBulkExecution = true
};
_accountName = accountName;
_client = new CosmosClient(
$"https://{_accountName}.documents.azure.com:443/",
key,
options);
_logger = logger.AddContext("account", accountName);
}
public async Task Execute(IJobExecutionContext context)
{
using (_logger.AddContext("Job", Id))
{
_logger.Information("Executing Job");
try
{
await DoWorkAsync(context);
_logger.Information("Job executed");
}
catch (System.Exception e)
{
_logger.Error(e);
}
}
}
public Task Handle(GameweekMonitoringStarted notification, CancellationToken cancellationToken)
{
using var scope = _logger.AddContext(Tuple.Create(nameof(GameweekMonitoringStarted), notification.CurrentGameweek.Id.ToString()));
_logger.LogInformation("Init");
return(_state.Reset(notification.CurrentGameweek.Id));
}
private async Task LoadStoredProceduresAsync()
{
if (_initialized == null)
{
throw new InvalidOperationException("InitializeAsync hasn't been called");
}
_logger.Display("Index Stored Procedures");
_logger.WriteEvent("Index-Collection-Sprocs-Start");
var bufferSizes = GetStoredProcedureBufferSizes();
var sprocs = await LoadUntilNowSprocsIndexAsync();
var batchCount = 0;
long lastTimeStamp = 0;
using (var buffer = new IndexingBuffer(
bufferSizes.indexSize,
bufferSizes.contentSize,
_initialized.IndexFile.PushDocumentsAsync))
{
await foreach (var batch in _initialized.LogFile.ReadStoredProceduresAsync(
_initialized.IndexFile.LastStoredProcedureTimeStamp,
_indexConstants.MaxLogBufferSize))
{
var batchIds = ImmutableHashSet <string> .Empty;
lastTimeStamp = batch.BatchTimeStamp;
++batchCount;
foreach (var item in batch.Items)
{
batchIds = batchIds.Add(item.Id.Id);
if (!sprocs.ContainsKey(item.Id.Id) ||
sprocs[item.Id.Id].TimeStamp < item.Id.TimeStamp)
{
var(metaData, content) = item.Split();
sprocs = sprocs.SetItem(item.Id.Id, metaData.Id);
await buffer.WriteAsync(metaData, content);
}
}
var deletedIds = sprocs.Keys.ToImmutableHashSet().Except(batchIds);
foreach (var id in deletedIds)
{
sprocs = sprocs.Remove(id);
await buffer.WriteAsync(new ScriptMetaData(
new ScriptIdentifier(id, lastTimeStamp), 0),
EMPTY_CONTENT);
}
}
await buffer.FlushAsync();
_initialized.IndexFile.UpdateLastSprocTimeStamp(lastTimeStamp);
_logger.Display($"Indexed {buffer.ItemCount} stored procedures in {batchCount} batches");
_logger
.AddContext("documentCount", buffer.ItemCount)
.AddContext("batchCount", batchCount)
.WriteEvent("Index-Collection-Sprocs-End");
}
_logger.WriteEvent("Index-Collection-Sprocs-End");
}
public DirectoryMonitor(ILogger logger, string endpoint, string directory)
{
if (string.IsNullOrEmpty(directory) || !Directory.Exists(Path.GetFullPath(directory)))
{
logger.Warn("Invalid import directory");
return;
}
if (string.IsNullOrEmpty(endpoint))
{
logger.Warn("Invalid web api endpoint");
return;
}
_logger = logger;
_directory = Path.GetFullPath(directory);
_client = new HttpClient
{
BaseAddress = new Uri(endpoint)
};
_client.DefaultRequestHeaders.Accept.Clear();
_client.DefaultRequestHeaders.Accept.Add(
new MediaTypeWithQualityHeaderValue("application/json"));
_watcher = new FileSystemWatcher(_directory, "*.txt")
{
IncludeSubdirectories = false
};
_watcher.Created += (object sender, FileSystemEventArgs e) =>
{
var fileName = Path.GetFileName(e.FullPath);
_logger.Debug("Processing {fileName}", fileName);
using (_logger.AddContext("ImportedFileName", fileName))
{
try
{
var todos = File.ReadAllLines(e.FullPath);
if (!todos.Any())
{
return;
}
foreach (var todo in todos)
{
try
{
AddTodo(todo).Wait();
}
catch
{
throw;
}
}
}
catch (Exception ex)
{
_logger.Error(ex);
}
}
};
_watcher.Error += (object sender, ErrorEventArgs e) =>
{
Exception ex = e.GetException();
_logger.Error(ex.Message);
if (ex.InnerException != null)
{
_logger.Error(ex.InnerException);
}
};
}
protected override async Task <HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
{
var apiLogEntry = CreateApiLogEntryWithRequestData(request);
var sw = new Stopwatch();
if (request.Content != null)
{
await request.Content.ReadAsStringAsync()
.ContinueWith(task =>
{
apiLogEntry.RequestContentBody = task.Result;
}, cancellationToken);
}
sw.Start();
return(await base.SendAsync(request, cancellationToken)
.ContinueWith(task =>
{
var response = task.Result;
sw.Stop();
var formattedTimeElapsed = sw.ElapsedMilliseconds.ToString(CultureInfo.InvariantCulture);
// Update the API log entry with response info
var statusCode = (int)response.StatusCode;
apiLogEntry.ResponseStatusCode = statusCode;
apiLogEntry.ResponseTimestamp = DateTime.Now;
if (response.Content != null)
{
apiLogEntry.ResponseContentBody = response.Content.ReadAsStringAsync().Result;
apiLogEntry.ResponseContentType = response.Content.Headers.ContentType.MediaType;
apiLogEntry.ResponseHeaders = SerializeHeaders(response.Content.Headers);
}
using (_logger.AddContext("CorrelationId", request.GetCorrelationId()))
{
/* * Logging levels
* All 400-499 http status codes are logged as Warnings
* All 500 > http status codes are logged as Errors
* All other requests are logged as Info
* */
if (statusCode >= 400 && statusCode <= 499)
{
_logger.Warn("HTTP {HttpMethod} {AbsoluteUrl} responded {StatusCode} in {EllapseTime} ms", apiLogEntry.RequestMethod.ToUpper(),
apiLogEntry.RequestUri, statusCode, formattedTimeElapsed);
}
else if (statusCode >= 500)
{
_logger.Error("HTTP {HttpMethod} {AbsoluteUrl} responded {StatusCode} in {EllapseTime} ms", apiLogEntry.RequestMethod.ToUpper(),
apiLogEntry.RequestUri, statusCode, formattedTimeElapsed);
}
else
{
_logger.Information("HTTP {HttpMethod} {AbsoluteUrl} responded {StatusCode} in {EllapseTime} ms", apiLogEntry.RequestMethod.ToUpper(),
apiLogEntry.RequestUri, statusCode, formattedTimeElapsed);
}
}
return response;
}, cancellationToken));
}
