예제 #1
0
        private ProcessTaskResult DoProcessTask([NotNull] TaskMetaInformation inProcessMeta, [NotNull] byte[] taskData, [NotNull] MetricsContext metricsContext)
        {
            metricsContext = metricsContext.SubContext(nameof(DoProcessTask));
            using (metricsContext.Timer("Total").NewContext())
            {
                IRtqTaskHandler taskHandler;
                try
                {
                    using (metricsContext.Timer("CreateHandlerFor").NewContext())
                        taskHandler = taskHandlerRegistry.CreateHandlerFor(inProcessMeta.Name);
                }
                catch (Exception e)
                {
                    logger.Error(e, "TaskHandler creation error for: {RtqTaskMeta}", new { RtqTaskMeta = inProcessMeta });
                    var newExceptionInfoIds = TrуAddExceptionInfo(e, inProcessMeta);
                    using (metricsContext.Timer("TrySwitchToTerminalState").NewContext())
                        return(new ProcessTaskResult(LocalTaskProcessingResult.Error, TrySwitchToTerminalState(inProcessMeta, TaskState.Fatal, newExceptionInfoIds)));
                }

                var task = new Task(inProcessMeta, taskData);
                using (TaskExecutionContext.ForTask(task))
                {
                    var sw = Stopwatch.StartNew();
                    try
                    {
                        HandleResult handleResult;
                        using (metricsContext.Timer("HandleTask").NewContext())
                            handleResult = taskHandler.HandleTask(taskProducer, serializer, task);
                        rtqProfiler.ProcessTaskExecutionFinished(inProcessMeta, handleResult, sw.Elapsed);
                        MetricsContext.For(inProcessMeta).Meter("TasksExecuted").Mark();
                        using (metricsContext.Timer("UpdateTaskMetaByHandleResult").NewContext())
                            return(UpdateTaskMetaByHandleResult(inProcessMeta, handleResult));
                    }
                    catch (Exception e)
                    {
                        rtqProfiler.ProcessTaskExecutionFailed(inProcessMeta, sw.Elapsed);
                        MetricsContext.For(inProcessMeta).Meter("TasksExecutionFailed").Mark();
                        logger.Error(e, "Unhandled exception in TaskHandler for: {RtqTaskMeta}", new { RtqTaskMeta = inProcessMeta });
                        var taskExceptionInfoId = TrуAddExceptionInfo(e, inProcessMeta);
                        using (metricsContext.Timer("TrySwitchToTerminalState").NewContext())
                            return(new ProcessTaskResult(LocalTaskProcessingResult.Error, TrySwitchToTerminalState(inProcessMeta, TaskState.Fatal, taskExceptionInfoId)));
                    }
                }
            }
        }
예제 #2
0
        public LocalTaskProcessingResult RunTask()
        {
            taskShardMetricsContext.Meter("Started").Mark();
            if (taskMeta == null)
            {
                taskShardMetricsContext.Meter("NoMeta").Mark();
                logger.Error("Удаляем запись индекса, для которой мета так и не записалась: {RtqTaskIndexRecord}", new { RtqTaskIndexRecord = taskIndexRecord });
                taskMinimalStartTicksIndex.RemoveRecord(taskIndexRecord, globalTime.UpdateNowTimestamp().Ticks);
                return(LocalTaskProcessingResult.Undefined);
            }
            var localNow = Timestamp.Now;

            if (taskIndexRecord != handleTasksMetaStorage.FormatIndexRecord(taskMeta) && taskIndexRecord.MinimalStartTicks > localNow.Ticks - MaxAllowedIndexInconsistencyDuration.Ticks)
            {
                taskShardMetricsContext.Meter("InconsistentIndexRecord").Mark();
                logger.Debug("taskIndexRecord != IndexRecord(taskMeta), поэтому ждем; taskMeta: {RtqTaskMeta}; taskIndexRecord: {RtqTaskIndexRecord}; localNow: {LocalNow}",
                             new { RtqTaskMeta = taskMeta, RtqTaskIndexRecord = taskIndexRecord, LocalNow = localNow });
                return(LocalTaskProcessingResult.Undefined);
            }
            var metricsContext = MetricsContext.For(taskMeta).SubContext(nameof(HandlerTask));

            return(TryProcessTaskExclusively(metricsContext));
        }
예제 #3
0
 public HandlerTask(
     [NotNull] TaskIndexRecord taskIndexRecord,
     TaskQueueReason reason,
     [CanBeNull] TaskMetaInformation taskMeta,
     IRtqTaskHandlerRegistry taskHandlerRegistry,
     IRtqInternals rtqInternals)
 {
     this.taskIndexRecord     = taskIndexRecord;
     this.reason              = reason;
     this.taskMeta            = taskMeta;
     this.taskHandlerRegistry = taskHandlerRegistry;
     serializer                 = rtqInternals.Serializer;
     taskProducer               = rtqInternals.TaskProducer;
     handleTaskCollection       = rtqInternals.HandleTaskCollection;
     remoteLockCreator          = rtqInternals.RemoteLockCreator;
     taskExceptionInfoStorage   = rtqInternals.TaskExceptionInfoStorage;
     handleTasksMetaStorage     = rtqInternals.HandleTasksMetaStorage;
     taskMinimalStartTicksIndex = rtqInternals.TaskMinimalStartTicksIndex;
     rtqProfiler                = rtqInternals.Profiler;
     globalTime                 = rtqInternals.GlobalTime;
     taskTtl = rtqInternals.TaskTtl;
     logger  = rtqInternals.Logger.ForContext(nameof(HandlerTask));
     taskShardMetricsContext = MetricsContext.For($"Shards.{taskIndexRecord.TaskIndexShardKey.TaskTopic}.{taskIndexRecord.TaskIndexShardKey.TaskState}.Tasks");
 }
예제 #4
0
 private LocalTaskProcessingResult TryProcessTaskExclusively([NotNull] MetricsContext metricsContext)
 {
     metricsContext = metricsContext.SubContext(nameof(TryProcessTaskExclusively));
     using (metricsContext.Timer("Total").NewContext())
     {
         IRemoteLock taskGroupRemoteLock = null;
         if (!string.IsNullOrEmpty(taskMeta.TaskGroupLock))
         {
             using (metricsContext.Timer("TryGetLock_TaskGroupLock").NewContext())
             {
                 if (!remoteLockCreator.TryGetLock(taskMeta.TaskGroupLock, out taskGroupRemoteLock))
                 {
                     taskShardMetricsContext.Meter("DidNotGetTaskGroupLock").Mark();
                     logger.Debug("Не смогли взять групповую блокировку {RtqTaskGroupLock} на задачу: {RtqTaskId}", new { RtqTaskGroupLock = taskMeta.TaskGroupLock, RtqTaskId = taskIndexRecord.TaskId });
                     return(LocalTaskProcessingResult.Undefined);
                 }
             }
             taskShardMetricsContext.Meter("GotTaskGroupLock").Mark();
         }
         try
         {
             var         sw = Stopwatch.StartNew();
             IRemoteLock remoteLock;
             using (metricsContext.Timer("TryGetLock_TaskId").NewContext())
             {
                 if (!remoteLockCreator.TryGetLock(taskIndexRecord.TaskId, out remoteLock))
                 {
                     taskShardMetricsContext.Meter("DidNotGetTaskLock").Mark();
                     logger.Debug("Не смогли взять блокировку на задачу, пропускаем её: {RtqTaskIndexRecord}", new { RtqTaskIndexRecord = taskIndexRecord });
                     return(LocalTaskProcessingResult.Undefined);
                 }
             }
             taskShardMetricsContext.Meter("GotTaskLock").Mark();
             LocalTaskProcessingResult result;
             using (remoteLock)
                 result = ProcessTask(metricsContext);
             sw.Stop();
             var isLongRunningTask = sw.Elapsed > longRunningTaskDurationThreshold;
             logger.Log(new LogEvent(
                            level: isLongRunningTask ? LogLevel.Warn : LogLevel.Debug,
                            timestamp: DateTimeOffset.Now,
                            messageTemplate: "Завершили выполнение задачи {RtqTaskId} с результатом {Result}. Отпустили блокировку {LockId}. Время работы с учетом взятия лока: {Elapsed}")
                        .WithObjectProperties(new
             {
                 RtqTaskId         = taskMeta.Id,
                 Result            = result,
                 LockId            = taskIndexRecord.TaskId,
                 Elapsed           = sw.Elapsed,
                 IsLongRunningTask = isLongRunningTask,
             }));
             return(result);
         }
         finally
         {
             if (taskGroupRemoteLock != null)
             {
                 taskGroupRemoteLock.Dispose();
                 logger.Debug("Отпустили групповую блокировку {RtqTaskGroupLock} в процессе завершения задачи {RtqTaskId}", new { RtqTaskGroupLock = taskMeta.TaskGroupLock, RtqTaskId = taskMeta.Id });
             }
         }
     }
 }
예제 #5
0
        private LocalTaskProcessingResult ProcessTask([NotNull] MetricsContext metricsContext)
        {
            metricsContext = metricsContext.SubContext(nameof(ProcessTask));
            using (metricsContext.Timer("Total").NewContext())
            {
                byte[] taskData;
                TaskMetaInformation oldMeta;
                try
                {
                    Task task;
                    using (metricsContext.Timer("GetTask").NewContext())
                        task = handleTaskCollection.GetTask(taskIndexRecord.TaskId);
                    oldMeta  = task.Meta;
                    taskData = task.Data;
                    if (oldMeta.NeedTtlProlongation())
                    {
                        logger.Error("oldMeta.NeedTtlProlongation(oldMeta.GetExpirationTimestamp()) == true for: {RtqTaskMeta}", new { RtqTaskMeta = oldMeta });
                    }
                }
                catch (Exception e)
                {
                    taskShardMetricsContext.Meter("ReadTaskException_UnderLock").Mark();
                    logger.Error(e, "Ошибка во время чтения задачи: {RtqTaskIndexRecord}", new { RtqTaskIndexRecord = taskIndexRecord });
                    return(LocalTaskProcessingResult.Undefined);
                }

                var localNow = Timestamp.Now;
                var indexRecordConsistentWithActualMeta = handleTasksMetaStorage.FormatIndexRecord(oldMeta);
                if (taskIndexRecord != indexRecordConsistentWithActualMeta)
                {
                    if (taskIndexRecord.MinimalStartTicks > localNow.Ticks - MaxAllowedIndexInconsistencyDuration.Ticks)
                    {
                        taskShardMetricsContext.Meter("InconsistentIndexRecord_UnderLock").Mark();
                        logger.Debug("После перечитывания меты под локом taskIndexRecord != IndexRecord(oldMeta), поэтому ждем; oldMeta: {RtqTaskMeta}; taskIndexRecord: {RtqTaskIndexRecord}; localNow: {LocalNow}",
                                     new { RtqTaskMeta = oldMeta, RtqTaskIndexRecord = taskIndexRecord, LocalNow = localNow });
                    }
                    else
                    {
                        if (oldMeta.State == TaskState.Finished || oldMeta.State == TaskState.Fatal || oldMeta.State == TaskState.Canceled)
                        {
                            taskShardMetricsContext.Meter("TaskAlreadyFinished_UnderLock").Mark();
                            logger.Error("После перечитывания меты под локом taskIndexRecord != IndexRecord(oldMeta) в течение {MaxAllowedIndexInconsistencyDuration} и задача уже находится в терминальном состоянии, " +
                                         "поэтому просто удаляем зависшую запись из индекса; oldMeta: {RtqTaskMeta}; taskIndexRecord: {RtqTaskIndexRecord}; localNow: {LocalNow}",
                                         new { MaxAllowedIndexInconsistencyDuration, RtqTaskMeta = oldMeta, RtqTaskIndexRecord = taskIndexRecord, LocalNow = localNow });
                            using (metricsContext.Timer("RemoveIndexRecord_Terminal").NewContext())
                                taskMinimalStartTicksIndex.RemoveRecord(taskIndexRecord, globalTime.UpdateNowTimestamp().Ticks);
                        }
                        else
                        {
                            logger.Error("После перечитывания меты под локом taskIndexRecord != IndexRecord(oldMeta) в течение {MaxAllowedIndexInconsistencyDuration}, поэтому чиним индекс; " +
                                         "oldMeta: {RtqTaskMeta}; taskIndexRecord: {RtqTaskIndexRecord}; indexRecordConsistentWithActualMeta: {IndexRecordConsistentWithActualMeta}; localNow: {LocalNow}",
                                         new { MaxAllowedIndexInconsistencyDuration, RtqTaskMeta = oldMeta, RtqTaskIndexRecord = taskIndexRecord, IndexRecordConsistentWithActualMeta = indexRecordConsistentWithActualMeta, LocalNow = localNow });
                            taskShardMetricsContext.Meter("FixIndex_UnderLock").Mark();
                            var globalNowTicks = globalTime.UpdateNowTimestamp().Ticks;
                            using (metricsContext.Timer("AddIndexRecord_FixIndex").NewContext())
                                taskMinimalStartTicksIndex.AddRecord(indexRecordConsistentWithActualMeta, globalNowTicks, oldMeta.GetTtl());
                            using (metricsContext.Timer("RemoveIndexRecord_FixIndex").NewContext())
                                taskMinimalStartTicksIndex.RemoveRecord(taskIndexRecord, globalNowTicks);
                        }
                    }
                    return(LocalTaskProcessingResult.Undefined);
                }

                var metricsContextForTaskName = MetricsContext.For(oldMeta);
                if (oldMeta.Attempts > 0)
                {
                    metricsContextForTaskName.Meter("RerunTask").Mark();
                }
                var waitedInQueue = Timestamp.Now - new Timestamp(oldMeta.FinishExecutingTicks ?? oldMeta.Ticks);
                if (waitedInQueue < TimeSpan.Zero)
                {
                    waitedInQueue = TimeSpan.Zero;
                }
                metricsContextForTaskName.Timer("TimeWaitingForExecution").Record((long)waitedInQueue.TotalMilliseconds, TimeUnit.Milliseconds);

                logger.Debug("Начинаем обрабатывать задачу oldMeta: {RtqTaskMeta}; Reason: {Reason}; taskIndexRecord: {RtqTaskIndexRecord}",
                             new { RtqTaskMeta = oldMeta, Reason = reason, RtqTaskIndexRecord = taskIndexRecord });
                TaskMetaInformation inProcessMeta;
                using (metricsContext.Timer("TrySwitchToInProcessState").NewContext())
                    inProcessMeta = TrySwitchToInProcessState(oldMeta);
                if (inProcessMeta == null)
                {
                    taskShardMetricsContext.Meter("StartProcessingFailed_UnderLock").Mark();
                    logger.Error("Не удалось начать обработку задачи. OldMeta: {RtqTaskMeta}", new { RtqTaskMeta = oldMeta });
                    return(LocalTaskProcessingResult.Undefined);
                }

                var processTaskResult = DoProcessTask(inProcessMeta, taskData, metricsContext);
                taskShardMetricsContext.Meter("Processed").Mark();

                var newMeta = processTaskResult.NewMeta;
                if (newMeta != null && newMeta.NeedTtlProlongation())
                {
                    logger.Debug("Продлеваем время жизни задачи после обработки. NewMeta: {RtqTaskMeta}", new { RtqTaskMeta = newMeta });
                    try
                    {
                        newMeta.SetOrUpdateTtl(taskTtl);
                        using (metricsContext.Timer("ProlongTaskTtl").NewContext())
                            handleTaskCollection.ProlongTaskTtl(newMeta, taskData);
                    }
                    catch (Exception e)
                    {
                        logger.Error(e, "Ошибка во время продления времени жизни задачи. NewMeta: {RtqTaskMeta}", new { RtqTaskMeta = newMeta });
                    }
                }

                return(processTaskResult.ProcessingResult);
            }
        }