У меня есть приложение UWP (C #), которое запущено в производство на удаленной машине (под Windows 10), но оно периодически вылетает.Мой клиент говорит, несколько произвольно, каждые 9 часов или около того.
У меня есть несколько файлов .wer из предыдущих сбоев, но у них не было минидампа, пути, указанные в записи средства просмотра событий для сбоя, являются пустыми, кроме файлов WER. См. Правки ниже, чтобы узнать, как был получен мини-дамп и получены результаты.
Исключением является нарушение прав доступа (0xc0000005) со смещением исключения 0x0004df23 в ntdll.dll
У меня естьполный исходный код приложения и может запускать его в режиме отладки в течение длительных периодов без сбоев.
Если я использую DLL Export Viewer и загружаю точную версию ntdll.dll (скопированную с удаленного компьютера), то я вижучто по относительному адресу 0x0004dc60 это EtwNotificationRegister, а по адресу 0x0004e260 это LdrGetDllPath.
Означает ли это, что мой сбой происходит в пределах строки кода в EtwNotificationRegister (который, в свою очередь, вызывается чем-то в нашем коде; однако очень трудно отследить без стека / минидампа) Я не уверен, что макетdll таков, что адрес, который я имею, может быть помещен как этот?
Редактировать 2 согласно @Raymond: Нет. Есть почти наверняка другие неэкспортированные функции между EtwNotificationRegister и LdrGetDllPath.В сборке 17763.475 смещение 4df23 равно RtlpWaitOnCriticalSection, поэтому вы, вероятно, используете неинициализированный критический раздел или уже удаленный критический раздел.
Можно ли как-нибудь подробнее узнать об этом сбое?У меня есть удаленный доступ к компьютеру, на котором запущено приложение, но сбой, похоже, не вызван определенным событием (например, мы не можем нажать кнопку и вызвать сбой)
Использование мини-дамп сейчас
Я также запускаю программу в локальной отладке.У меня есть удаленный отладчик для удаленного процесса, но я не могу сломать или проверить потоки, не знаю почему.При повторном развертывании с символами отладчик не создает проблем, но пропускает все точки останова: (
Наш собственный (довольно наивный) локальный файл журнала, изначально предназначенный только для локальной отладки, записывается с StreamWriter.WriteLine и сразу же следуетс StreamWriter.Flush (обернутым в try catch, так как он не является потокобезопасным) просто заканчивается обычным событием на удаленной машине - после этого нормального события ничего не происходит.стек здесь.
В Необъяснимые сбои, связанные с ntdll.dll Предполагается, что сбой из ntdll.dll является канарейкой в шахте Необъяснимые сбои, связанные с ntdll.dll
Редактировать 1: Я настроил автоматический аварийный дамп согласно https://www.meziantou.net/2018/06/04/tip-automatically-create-a-crash-dump-file-on-error, поэтому, если я смогу снова вызвать его сбой, возможно, я получу файл дампа в следующий раз?
Вот деталь из WER
Version=1
EventType=MoAppCrash
EventTime=132017523132123596
ReportType=2
Consent=1
UploadTime=132017523137590717
ReportStatus=268435456
ReportIdentifier=8d467f04-4bdd-4f9e-bf26-b42d143ece1a
IntegratorReportIdentifier=b60f9ca0-4126-4262-a886-98d3844892d3
Wow64Host=34404
NsAppName=praid:App
OriginalFilename=XXXXXX.YYYYYY.exe
AppSessionGuid=00001514-0001-0004-9fe2-6df11905d501
TargetAppId=U:XXXXXX.YYYYYY_1.0.201.0_x64__b0abmt6f49vqj!App
TargetAppVer=1.0.201.0_x64_!2018//01//24:08:17:16!1194d!XXXXXX.YYYYYY.exe
BootId=4294967295
TargetAsId=1298
UserImpactVector=271582000
IsFatal=1
EtwNonCollectReason=4
Response.BucketId=2ee79f27e2e81a541d6200d746866340
Response.BucketTable=5
Response.LegacyBucketId=2117255699418735424
Response.type=4
Sig[0].Name=Package Full Name
Sig[0].Value=XXXXXX.YYYYYY_1.0.201.0_x64__b0abmt6f49vqj
Sig[1].Name=Application Name
Sig[1].Value=praid:App
Sig[2].Name=Application Version
Sig[2].Value=1.0.0.0
Sig[3].Name=Application Timestamp
Sig[3].Value=5a68410c
Sig[4].Name=Fault Module Name
Sig[4].Value=ntdll.dll
Sig[5].Name=Fault Module Version
Sig[5].Value=10.0.17763.475
Sig[6].Name=Fault Module Timestamp
Sig[6].Value=3230aa04
Sig[7].Name=Exception Code
Sig[7].Value=c0000005
Sig[8].Name=Exception Offset
Sig[8].Value=000000000004df23
DynamicSig[1].Name=OS Version
DynamicSig[1].Value=10.0.17763.2.0.0.256.48
DynamicSig[2].Name=Locale ID
DynamicSig[2].Value=5129
DynamicSig[22].Name=Additional Information 1
DynamicSig[22].Value=95b1
DynamicSig[23].Name=Additional Information 2
DynamicSig[23].Value=95b15a88b673e33a5f48839974790b1c
DynamicSig[24].Name=Additional Information 3
DynamicSig[24].Value=283d
DynamicSig[25].Name=Additional Information 4
DynamicSig[25].Value=283dea7b6b6112710c1e3f76ed84d993
Редактировать 3: скриншот минидампа после аварии прошлой ночью.В журнале событий сбой WER выглядит одинаково, поэтому проблема, похоже, та же.Я посмотрю, смогу ли я загрузить символы и т. Д.
Редактировать 4: Попытка отладки выполнена.Представление «Потоки» показывает поток в качестве точки исключения, но не содержит информации стека вызовов.
Редактировать 5: Отладка нативного кода из мини-дампа.Похоже, у нас есть победитель.@Raymond был прав, это был RtlpWaitOnCriticalSection, вызванный из BluetoothLEAdvertismentWatcher :: AdvertismentReceivedCallbackWorker
Собственный стек вызовов в виде текста:
Не отмечен> 8748 0 Рабочая тема Win64 Тема Windows.Devices.Bluetooth.dll! (Void) ntdll.dll! RtlpWaitOnCriticalSection () ntdll.dll! RtlpEnterCriticalSectionContended () ntdll.dll! RtlEnterCriticalSection ()Windows.Devices.Bluetooth.dll! (Void) () Windows.Devices.Bluetooth.dll! Wil :: ResultFromException <(void) </p>
() Windows.Devices.Bluetooth.dll! Windows:: Устройства :: Bluetooth :: Реклама :: BluetoothLEAdvertisingWatcher :: AdvertisingReceivedCallbackWorker (void) Windows.Devices.Bluetooth.dll! Windows :: Устройства :: Bluetooth :: Реклама :: BluetoothLEAdvertisingWatcher :: AdvertisingReceivedThreadpoolWorkCallbackStatic (struct _TP_CALLBACK_INSTANCE *, void *, struct_TP_WORK *) ntdll.dll! TppWorkpExecuteCallback () ntdll.dll! TppWorkerThread () kernel32.dll! BaseThreadInitThunk () ntdll.dll! RtlUserThreadStart ()
Редактировать 6: хорошо, теперь,что я делаю?Как я могу решить эту проблему?Мое понимание стека это выглядит так, как будто исключение было сгенерировано внутри обратного вызова?Это верно?Таким образом, я мог бы поместить управляемый try / catch в обработчик обратного вызова рекламы BLE, и это должно (catch - для дальнейшей отладки) исправить это?
Редактировать 7: код ... Вот код, который мы используем для создания экземпляраОбертка и подписаться на события.BluetoothLEAdtactWatcherWrapper является классом разделения (например, он просто оборачивает базовый BluetoothLEAdvertisingWatcher, чтобы он мог реализовать интерфейс; он просто пропускает все события и выставляет свойства. Мы делаем это, чтобы у нас была другая версия, которая создает виртуальные события для тестирования)
bluetoothAdvertisementWatcher = new BluetoothLEAdvertisementWatcherWrapper();
bluetoothAdvertisementWatcher.SignalStrengthFilter.SamplingInterval = TimeSpan.Zero;
bluetoothAdvertisementWatcher.ScanningMode = BluetoothLEScanningMode.Active;
bluetoothAdvertisementWatcher.Received += Watcher_Received;
bluetoothAdvertisementWatcher.Stopped += Watcher_Stopped;
bluetoothAdvertisementWatcher.Start();
Вот код для оболочки;просто чтобы показать, что он не делает ничего сложного:
public class BluetoothLEAdvertisementWatcherWrapper : IBluetoothAdvertismentWatcher, IDisposable
{
private BluetoothLEAdvertisementWatcher bluetoothWatcher;
public BluetoothLEAdvertisementWatcherWrapper()
{
bluetoothWatcher = new BluetoothLEAdvertisementWatcher();
}
public BluetoothSignalStrengthFilter SignalStrengthFilter => bluetoothWatcher.SignalStrengthFilter;
public BluetoothLEScanningMode ScanningMode
{
get
{
return bluetoothWatcher.ScanningMode;
}
set
{
bluetoothWatcher.ScanningMode = value;
}
}
public event TypedEventHandler<BluetoothLEAdvertisementWatcher, BluetoothLEAdvertisementReceivedEventArgs> Received
{
add
{
bluetoothWatcher.Received += value;
}
remove
{
bluetoothWatcher.Received -= value;
}
}
public event TypedEventHandler<BluetoothLEAdvertisementWatcher, BluetoothLEAdvertisementWatcherStoppedEventArgs> Stopped
{
add
{
bluetoothWatcher.Stopped += value;
}
remove
{
bluetoothWatcher.Stopped -= value;
}
}
public BluetoothLEAdvertisementWatcherStatus Status => bluetoothWatcher.Status;
public Action<IPacketFrame, short> YieldAdvertisingPacket { get => throw new NotImplementedException(); set => throw new NotImplementedException(); }
public void Start()
{
bluetoothWatcher.Start();
}
public void Stop()
{
bluetoothWatcher.Stop();
}
public void Dispose()
{
if (bluetoothWatcher != null)
{
if (bluetoothWatcher.Status == BluetoothLEAdvertisementWatcherStatus.Started)
{
bluetoothWatcher.Stop();
}
bluetoothWatcher = null;
}
}
}
А вот код для обработчика события Watcher_Received:
private void Watcher_Received(BluetoothLEAdvertisementWatcher sender, BluetoothLEAdvertisementReceivedEventArgs args)
{
try
{
//we won't queue packets until registered
if (!ApplicationContext.Current.Details.ReceiverId.HasValue)
return;
IPacketFrame frame;
PacketFrameParseResult result = ParseFrame(args, out frame);
if (result == PacketFrameParseResult.Success)
{
ApplicationContext.Current.Details.BluetoothPacketCount++;
}
short rssi = args.RawSignalStrengthInDBm;
string message = FormatPacketForDisplay(args, args.AdvertisementType, rssi, frame, result);
if (BluetoothPacketReceived != null)
{
BluetoothPacketReceived.Invoke(this, new BluetoothPacketReceivedEventArgs(message, result, frame, rssi));
}
}
catch (Exception ex)
{
if (ex.InnerException is Exceptions.PacketFrameParseException && (ex.InnerException as Exceptions.PacketFrameParseException).Result == PacketFrameParseResult.InvalidData)
{
// noop
}
else
{
Logger.Log(LogLevel.Warning, "BLE listener caught bluetooth packet error: {0}", ex);
if (BluetoothPacketError != null)
{
BluetoothPacketError.Invoke(this, new BluetoothPacketErrorEventArgs(ex));
}
}
}
}
Здесь вы видите, что весь управляемый обратный вызов заключен впопытка поймать и не перебрасывать, так что я не уверен, что смогу ли я что-нибудь предпринять, чтобы предотвратить отключение приложения нативным исключением.
Текущее мышление, основанное на этом: RtlpEnterCriticalSectionContended isэто параллельный обработчик событий, нативная сторона вызывает обработчик, и он вызывает новое событие в том же потоке, в то время как предыдущий обработчик все еще выполняется из предыдущего события?Тогда это условие гонки в критической секции, которая вызывает сбой?
Правка 8: Чтобы проверить эту теорию, я заменил содержимое полученного сообщения на чтение + нажатие в параллельную очередь, позволяя управляемому кодувыйдите из обработчика событий как можно быстрее.Затем добавил отдельное чтение потока из параллельной очереди, чтобы выполнить обработку на стороне моего приложения.Первоначально я думал, что это решило проблему, поскольку приложение (прослушивание) работало в течение приблизительно 15 часов, однако сегодня утром оно снова зависало с теми же симптомами.
Редактировать 8: Следуя предложениям в комментариях, мы попыталисьчтобы убедиться, что мы не утилизировали наблюдателя после остановки до завершения приема.Мы сделали это, используя TaskCompletionSource для выполнения функции обещания, подписавшись на событие Stopped, чтобы мы могли ожидать исходную задачу завершения, которая будет иметь набор результатов только при наступлении события Stopped.
Мы также использовалиблокировка (Monitor.Enter) в StopAsync и Received, чтобы гарантировать, что оба не могут работать параллельно.Это, по-видимому, снижает скорость, с которой система может обрабатывать события, которые имели бы смысл, если бы пакеты BLE приходили параллельно.Обновлен код следующим образом:
if ((DateTime.Now - this.LastStartedTimestamp).TotalSeconds > 60)
{
if (this.LastStopReason != BluetoothWatcherStopReason.DeviceCharacteristicWorker)
{
Logger.Log(LogLevel.Debug, "Stopping bluetooth watcher...");
// restart watcher every 10 mins
await this.StopAsync(BluetoothWatcherStopReason.AutomaticRestart);
//start again if automatic restart
Logger.Log(LogLevel.Debug, "Starting bluetooth watcher...");
this.Start(this.testMode);
Logger.Log(LogLevel.Debug, "Started bluetooth watcher");
this.LastStartedTimestamp = DateTime.Now;
}
}
private void Watcher_Stopped(BluetoothLEAdvertisementWatcher sender, BluetoothLEAdvertisementWatcherStoppedEventArgs args)
{
string error = args.Error.ToString();
Logger.Log(LogLevel.Warning, string.Format("BLE listening stopped because {0}...", error));
LastError = args.Error;
if (BluetoothWatcherStopped != null)
{
BluetoothWatcherStopped.Invoke(sender, args);
}
}
public class ReceivedBluetoothAdvertismentPacketItem
{
public DateTime Timestamp { get; set; }
public BluetoothLEAdvertisementType Type { get; set; }
public byte[] Buffer { get; set; }
public short Rssi { get; set; }
}
ConcurrentQueue<ReceivedBluetoothAdvertismentPacketItem> BluetoothPacketsReceivedQueue = new ConcurrentQueue<ReceivedBluetoothAdvertismentPacketItem>();
private void Watcher_Received(BluetoothLEAdvertisementWatcher sender, BluetoothLEAdvertisementReceivedEventArgs args)
{
bool lockWasTaken = false;
try
{
//this prevents stop until we're exiting Received
Monitor.Enter(BluetoothWatcherEventSynchronisation, ref lockWasTaken);
if (!lockWasTaken)
{
return;
}
//we won't queue packets until registered
if (!ApplicationContext.Current.ReceiverDetails.ReceiverId.HasValue)
return;
BluetoothLEAdvertisementType type = args.AdvertisementType;
byte[] buffer = GetManufacturerData(args.Advertisement);
short rssi = args.RawSignalStrengthInDBm;
BluetoothPacketsReceivedQueue.Enqueue(new ReceivedBluetoothAdvertismentPacketItem
{
Timestamp = DateTime.UtcNow,
Type = type,
Rssi = rssi,
Buffer = buffer
});
ApplicationContext.Current.ReceiverDetails.UnprocessedQueueLength = BluetoothPacketsReceivedQueue.Count;
}
catch (Exception ex)
{
Logger.Log(LogLevel.Warning, "BLE listener caught bluetooth packet error: {0}", ex);
if (BluetoothPacketError != null)
{
BluetoothPacketError.Invoke(this, new BluetoothPacketErrorEventArgs(ex));
}
}
finally
{
if (lockWasTaken)
{
Monitor.Exit(BluetoothWatcherEventSynchronisation);
}
}
}
public BluetoothWatcherStopReason LastStopReason { get; private set; } = BluetoothWatcherStopReason.Unknown;
private object BluetoothWatcherEventSynchronisation = new object();
public Task<BluetoothWatcherStopReason> StopAsync(BluetoothWatcherStopReason reason)
{
var promise = new TaskCompletionSource<BluetoothWatcherStopReason>();
if (bluetoothAdvertisementWatcher != null)
{
LastStopReason = reason;
UpdateBluetoothStatusInReceiverModel(BluetoothLEAdvertisementWatcherStatus.Stopped); //actually stopping but we lie
bool lockWasTaken = false;
try
{
Monitor.Enter(BluetoothWatcherEventSynchronisation, ref lockWasTaken);
{
bluetoothAdvertisementWatcher.Received -= Watcher_Received;
bluetoothAdvertisementWatcher.Stopped += (sender, args) =>
{
// clean up
if (bluetoothAdvertisementWatcher != null)
{
bluetoothAdvertisementWatcher.Stopped -= Watcher_Stopped;
bluetoothAdvertisementWatcher = null;
}
//notify continuation
promise.SetResult(reason);
};
bluetoothAdvertisementWatcher.Stop();
}
}
finally
{
if (lockWasTaken)
{
Monitor.Exit(BluetoothWatcherEventSynchronisation);
}
}
}
base.Stop();
return promise.Task;
}
После этих изменений все еще происходит сбой в родной сборке Windows.Devices.Bluetooth (как указано выше)
Редактировать 9:убрал автоматический периодический запуск / остановка, и теперь приложение работало стабильно> 36 часов без сбоев.Так что что-то внутри этого потока вызывает сбои.Первоначально мы добавили это, чтобы обойти проблему, когда наблюдатель за рекламой просто останавливается через некоторое время, поэтому мы хотели бы оставить ее, если сможем ее исправить.Оператор if if ((DateTime.Now - this.LastStartedTimestamp).TotalSeconds > 60) (и блок) в настоящее время комментируется.
Я открыл ошибку для windows universal здесь: https://wpdev.uservoice.com/forums/110705-universal-windows-platform/suggestions/37623343-bluetoothleadvertismentwatcher-advertismentreceiv