Журналы веб-задания Azure - поиск журналов, в которых подробно описывается обработка SDK элементов, запускаемых очередью.

Как показано в моем вопросе о переполнении стека Веб-задание Azure не соответствует свойству MaxDequeueCount, я устраняю проблему, когда, несмотря на то, что я установил для свойства MaxDequeueCount значение 1, некоторые элементы удаляются из очереди много раз, прежде чем они будут отравлены (на самом деле некоторые элементы могут никогда не быть отравленным и просто исключать из очереди, терпеть неудачу, повторять попытки и терпеть неудачу бесконечно).

SDK Webjobs автоматически обрабатывает повторные попытки и отравление сообщений, инициированных очередью, и я ищу журналы, которые содержат подробную информацию об этой обработке.

Например, я могу видеть, что моя функция обнаружила новый элемент очереди, просмотрев журнал веб-задания через SCM в https://myappengine.scm.azurewebsites.net/vfs/data/jobs/continuous/StuffProcessor/job_log.txt (Кстати, если я включил подробное ведение журнала в хранилище Azure в веб-приложении, могу ли я получить эту же информацию в Blob?).

[02/22/2017 01:47:22 > ec8d0f: INFO] Executing: 'StuffProcessor.ProcessQueueMessage' - Reason: 'New queue message detected on 'stuff-processor'.'
[02/22/2017 01:47:26 > ec8d0f: INFO] Executed: 'StuffProcessor.ProcessQueueMessage' (Succeeded)
[02/22/2017 01:47:26 > ec8d0f: INFO] Executing: 'StuffProcessor.ProcessQueueMessage' - Reason: 'New queue message detected on 'stuff-processor'.'

Я также могу получить некоторую информацию о количестве исключений элемента из очереди, просмотрев журналы в контейнере azure-jobs-host-archive, как только я включу подробное ведение журнала в хранилище Azure в веб-приложении:

{
      "Type": "FunctionCompleted",
      "EndTime": "2017-02-22T00:07:40.8133081+00:00",
      "Failure": {
        "ExceptionType": "Microsoft.Azure.WebJobs.Host.FunctionInvocationException",
        "ExceptionDetails": "Microsoft.Azure.WebJobs.Host.FunctionInvocationException: Exception while executing function: ItemProcessor.ProcessQueueMessage ---> MyApp.Exceptions.MySpecialAppExceptionType: Exception of type 'MyApp.Exceptions.MySpecialAppExceptionType' was thrown.
      },
      "ParameterLogs": {},
      "FunctionInstanceId": "1ffac7b0-1290-4343-8ee1-2af0d39ae2c9",
      "Function": {
        "Id": "MyApp.Processors.ItemProcessor.ProcessQueueMessage",
        "FullName": "MyApp.Processors.ItemProcessor.ProcessQueueMessage",
        "ShortName": "ItemProcessor.ProcessQueueMessage",
        "Parameters": [
          {
            "Type": "QueueTrigger",
            "AccountName": "MyStorageAccount",
            "QueueName": "stuff-processor",
            "Name": "sourceFeedItemQueueItem"
          },
          {
            "Type": "BindingData",
            "Name": "dequeueCount"
          },
          {
            "Type": "ParameterDescriptor",
            "Name": "logger"
          }
        ]
      },
      "Arguments": {
        "sourceFeedItemQueueItem": "{\"SourceFeedUpdateID\":437530,\"PodcastFeedID\":\"2d48D2sf2\"}",
        "dequeueCount": "96",
        "logger": null
      },
      "Reason": "AutomaticTrigger",
      "ReasonDetails": "New queue message detected on 'stuff-processor'.",
      "StartTime": "2017-02-22T00:07:40.6017341+00:00",
      "OutputBlob": {
        "ContainerName": "azure-webjobs-hosts",
        "BlobName": "output-logs/1ffd3c7b012c043438ed12af0d39ae2c9.txt"
      },
      "ParameterLogBlob": {
        "ContainerName": "azure-webjobs-hosts",
        "BlobName": "output-logs/1cf2c1b012sa0d3438ee12daf0d39ae2c9.params.txt"
      },
      "LogLevel": "Info",
      "HostInstanceId": "d1825bdb-d92a-4657-81a4-36253e01ea5e",
      "HostDisplayName": "ItemProcessor",
      "SharedQueueName": "azure-webjobs-host-490daea03c70316f8aa2509438afe8ef",
      "InstanceQueueName": "azure-webjobs-host-d18252sdbd92a4657d1a436253e01ea5e",
      "Heartbeat": {
        "SharedContainerName": "azure-webjobs-hosts",
        "SharedDirectoryName": "heartbeats/490baea03cfdfd0416f8aa25aqr438afe8ef",
        "InstanceBlobName": "zd1825bdbdsdgga465781a436q53e01ea5e",
        "ExpirationInSeconds": 45
      },
      "WebJobRunIdentifier": {
        "WebSiteName": "myappengine",
        "JobType": "Continuous",
        "JobName": "ItemProcessor",
        "RunId": ""
      }
    }

Что я не могу найти, так это журналы, в которых показаны подробности для конкретного элемента очереди, обработка которого не выполняется из-за исключения и помещается в очередь с ошибками. Я ищу их, чтобы в дальнейшем устранить явное игнорирование свойства MaxDequeueCount. Это зарегистрировано?

ОБНОВЛЕНИЕ: я нашел сообщение Веб-задания Azure с очередью хранилища и исключениями, и он содержал следующий снимок экрана:

Консоль веб-заданий

На этом снимке экрана показаны стандартные сообщения «Обнаружено новое сообщение в очереди ...» (которые я вижу как в Azure, так и выполняющиеся локально в эмуляторе), а также показывает «Сообщение достигло MaxDequeueCount из X ... Перемещение сообщения в очередь 'xyz- яд '", который я только вижу локально в эмуляторе. Разве среда выполнения на основе Azure по какой-то причине не отображает эту информацию? Я никогда не вижу подобных сообщений, связанных с отравлением, при локальном запуске в окне консоли, через панель управления веб-заданиями или при работе в Azure.


person Howiecamp    schedule 22.02.2017    source источник


Ответы (2)


Вы используете службу хранилища Azure версии 8. *? Он содержит критическое изменение.

Когда объект сообщения очереди вставляется в очередь сообщений в службе хранилища Azure 8, идентификатор сообщения исходного объекта сообщения очереди перезаписывается уникальным идентификатором вновь вставленного сообщения.

Это означает, что он теряет ссылку на опасное сообщение и больше не может его удалить.

https://github.com/Azure/azure-webjobs-sdk/issues/985

Что касается логирования, то 2 варианта:

  1. Создайте свои собственные QueueProcessorFactory и QueueProcessor - вы можете переопределить метод, обрабатывающий подозрительные сообщения, для получения большего количества отладочных данных. Там вы также можете полностью решить проблему, если хотите остаться в службе хранилища Azure 8. *.

  2. Зарегистрируйте монитор трассировки. https://github.com/Azure/azure-webjobs-sdk-extensions/wiki/Error-Monitoring#tracemonitor

    var traceMonitor = new TraceMonitor()
    .Filter(p => true, "Trace Handler")
    .Subscribe(TraceHandler.Process);
    
    config.Tracing.Tracers.Add(traceMonitor);
    
person Bio2hazard    schedule 09.03.2017
comment
Бинго! Вы справились - это моя проблема. А пока я возвращаюсь к 7.x. Не для придирки, но я не думаю, что это критическое изменение; Думаю, это ошибка. Критическое изменение - это изменение поведения, которое не имеет обратной совместимости с предыдущим кодом. Возможно, это тоже правда, но мне это определенно кажется категорией «ошибок» ...? - person Howiecamp; 13.03.2017
comment
Что касается ведения журнала, не могли бы вы уточнить, действительно ли я должен видеть ядовитые сообщения элемента, инициируемые очередью веб-заданий, в стандартном выводе панели мониторинга веб-заданий при работе в Azure или нет? Как я уже говорил, я их вижу только локально. - person Howiecamp; 13.03.2017
comment
Не думаю, что это ошибка. Это изменение имеет смысл для группы хранения. Это похоже на то, как объект ORM будет заполнять поле Id после сохранения его в БД с полем Id, сгенерированным db. Не совсем понимаю, что вы имеете в виду, говоря о ведении журнала, но в выводе панели управления kudu (yoursite.scm.azurewebsites.net/azurejobs/#/jobs/continuous/YourWebJob) я вижу запись о перемещении чего-либо в очередь подозрений: [03/08/2017 00:39:46 > 730f59: INFO] Message has reached MaxDequeueCount of 2. Moving message to queue 'queue-poison'. - person Bio2hazard; 15.03.2017
comment
Теперь я знаю, почему не вижу этого сообщения; это потому, что мое отравление прервано, поскольку я нахожусь на 8.x ... Что касается вопроса о критическом изменении и ошибке, я понимаю следующее: когда объект сообщения очереди вставляется в очередь сообщений в Хранилище Azure 8, сообщение Идентификатор исходного объекта сообщения очереди перезаписывается уникальным идентификатором вновь вставленного сообщения. но похоже, что 8.x также каким-то образом нарушает поведение MaxDequeueCount. - person Howiecamp; 30.03.2017
comment
Вы говорите о двух совершенно разных пакетах и ​​командах в Microsoft. Одна из них - группа хранения, которая выпустила обновление 8.x, содержащее изменение функциональности. Однако у них нет понятия MaxDequeueCount или какого-либо поведения, которое могло бы его вызвать. А затем у вас есть пакет и команда azure-webjobs-sdk - они обрабатывают поведение MaxDequeueCount. По сути, azure-webjobs-sdk просто не создавалась с учетом 8.x. Это разные вещи. - person Bio2hazard; 31.03.2017

В вашем предыдущем посте у вас есть триггерная функция, как показано ниже.

public void ProcessQueueMessage([QueueTrigger("azurewejobtestingqueue")] string item, TextWriter logger)
{
   if ( item == "exception" )
   {
      throw new Exception();
   }
}

Все, что вы пишете в регистратор, должно отображаться в журналах на панели управления WebJobs. Мои предложения:

  1. Измените 'if (item == "exception")' на 'if (item.ToLower (). StartsWith ("exception")'. Затем добавьте номер в сообщение об исключении при тестировании. Зарегистрируйте текст сообщения очереди в TextWriter, чтобы вы могли быть уверены, что просматриваете то же сообщение, которое, по вашему мнению, проверяете.

  2. Вы можете получить счетчик выхода сообщения из очереди в качестве параметра функции. См. здесь. Обратите внимание на метод FailAlways в примере. Зарегистрируйте это также в TextWriter.

  3. Попробуйте запустить это локально. Весь вывод будет записан в окно консоли. Посмотрите, будет ли у вас такое же поведение.

Мне действительно интересно выяснить, что вызывает такое поведение, поэтому обязательно сообщите нам, если вы его взломаете!

person Rob Reagan    schedule 22.02.2017
comment
Все еще пытаюсь запустить его локально - я подумал, что ваше предложение было правильным. У меня нет проблем с отправкой всего в регистратор - сейчас я так и делаю. Я ищу, чтобы увидеть, что делает SDK - чтобы устранить неполадки в поведении, которое я хочу видеть, как SDK пытается отравить (или нет) сообщение. Мой if (item=="exception") был просто псевдокодом, а не буквальным кодом. Он просто предназначен для ссылки на элемент в очереди, который вызовет исключение. В настоящее время я получаю dequeueCount элемента в качестве параметра (я добавил его), и я могу видеть в своих журналах dequeueCounts для некоторых элементов, которые становятся все выше и выше. - person Howiecamp; 22.02.2017
comment
Просто чтобы добавить второй комментарий - у меня нет проблем с перехватом исключений - проблема в том, что я не понимаю, почему sdk не отравляет сообщения после того, как MaxDequeueCount несколько раз. - person Howiecamp; 22.02.2017
comment
При тестировании у вас есть один экземпляр, работающий в Azure и попадающий в очередь хранилища, которая также находится в Azure? - person Rob Reagan; 22.02.2017
comment
да. Единый экземпляр веб-задания / веб-сайта, а также размер пакета 1. Использование очередей хранилища Azure. (Очереди должны находиться в Azure, чтобы использовать функцию, запускаемую с помощью очереди SDK.) - person Howiecamp; 22.02.2017