Сага о E_RPC_DISCONNECT

Вначале был код

И был тот код написан на дотнете (еще версии 1.1) много лет назад. Код был простой и дубовый — где-то в дебрях проекта лежала стопка Interop*.*.DLL для еще более древних TLB. Очевидно, был заведен интерфейс, имплементирующий три с половиной метода, и рожден в муках набор реализаций, к моменту раскопок — их было шестнадцать (!) штук. Factory и прочие синглтоны — в комплекте.

Создавал тот код классический Application, и у всех 16 реализаций в интересующем нас месте код был скопипастан и идентичен — отличались лишь неймспейсы из интеропов.

Примерно вот так:

Type apptype = Type.GetTypeFromProgID("CoolAppID", false);
var app = Activator.CreateInstance(apptype) as Cool.Application;

var lib = app.Open(file, ... /* many flags */) as Cool.Library;
foreach(var asset in lib.Assets) {
    /* some long operations */
}

С тех пор код пережил много всего — переезд на дотнеты 2.0, 3.5, 4.0 и т. д. Стал поддерживать тех интеропов с двух до упомянутых шестнадцати — а код все тот же и все так же не меняется, лишь размножается почкованием иногда. Ни одного разрыва с 2007 года. Пока однажды не запустили этот код на Windows 8.1.

И злая колдунья уже хотела съесть Ганса и Гретель

А посетил этот кусок динозавра небезызвестный E_RPC_TIMEOUT. Причем на разных версиях того COM server, так что дело явно в коде.

Фигня вопрос! Оно ж работает очень долго, так? Значит итератор просто не доживает до конца цикла! — подумали те кто фиксил до меня.

Меняем:

...
var lib = app.Open(file, ... /* many flags */) as Cool.Library;
var list = new List<CoolAsset>();
foreach(var asset in lib.Assets) {
   list.Add(asset);
}

foreach(var asset in list) {
    /* some long operations */
}

/* some other stuff */
/* end of function */

Гм гм. Лучше не стало.

Не сказать чтобы совсем не попали — но не попали в шарик

Оно как бы помогло — в том смысле что E_RPC_TIMEOUT исчез. Но на его место пришел еще более злой E_RPC_DISCONNECT. И в этот момент до меня докатили этот рояль.

Инструменты и материалы:

• Windows 8.1 — одна штука
• Странный проект — 1 шт
• Адоуби ИнДиз Ах какой внешний ком сервер — 6 шт, воспроизводится на всех
• Секретный бубен — 1 шт

Приступим.

Атака на зебрах

Перво-наперво вооружаемся методами из далекого и темного прошлого, а именно — насуем каждой второй строчкой вывод в лог (да, я знаю про отладчик). Примерно так:

...
var lib = app.Open(file, ... /* many flags */) as Cool.Library;
var list = new List<CoolAsset>();
foreach(var asset in lib.Assets) {
   list.Add(asset);
}

try {
    log(">> foreach");
    foreach(var asset in list) {
        log(">> foreach got " + asset);
        /* some long operations */
        log(">> foreach asset " + asset + " is OK");
    }
    log("<< foreach");
}
catch (Exception e) {
    log(">> foreach failed due to " + e + "n" + e.StackTrace);
}
/* some other stuff */
/* end of function */

Запускаем, медитируем, и что мы видим?

>> foreach
>> foreach got foo
...
>> foreach asset foo is OK
...
>> foreach got bar
...
>> foreach asset bar is OK
>> foreach failed due to COMException ... E_RPC_DISCONNECT ... 

То есть, глядя на код —

        log(">> foreach asset " + asset + " is OK");
    }
    log("<< foreach");

Упало на закрывающей фигурной скобке.

Как такое может быть?

...
try {
    log(">> foreach");
    var itr = list.GetEnumerator();
    for(;;) {
        log(">> foreach new cycle...");
        if(!itr.MoveNext()) break;
        log(">> foreach new cycle and it have extra elements to iterate...");
        var asset = itr.Current;
        log(">> foreach got " + asset);
        /* some long operations */
        log(">> foreach asset " + asset + " is OK");
    }
    log("<< foreach");
}
catch (Exception e) {
    log(">> foreach failed due to " + e + "n" + e.StackTrace);
}
/* some other stuff */
/* end of function */

Разумеется в логе получаем вот такое

>> foreach
>> foreach new cycle...
>> foreach new cycle and it have extra elements to iterate...
>> foreach got foo
...
>> foreach asset foo is OK
...
>> foreach got bar
...
>> foreach asset bar is OK
>> foreach new cycle...
>> foreach failed due to COMException ... E_RPC_DISCONNECT ... 

То есть падает — на MoveNext().

Но постойте! Это же pure .NET iterator from pure .NET List<T>! Это вообще как? По сути, мы всего лишь пробежались за собственным хвостом, ничего не обнаружив.

Хвост вертит собакой

Взяв еще кофе и открыв мануал, а также громко поругав индусов обоих компаний, я выбрасываю все эксперименты вообще, привожу к исходному виду, и заменяю на счетчик с циклом цикл со счетчиком:

...
    for(int i=0; i < lib.Assets.Count; ++i) {
        var asset = lib.Assets[i];
        /* some long operations */
    }
...

Каково же было мое (и не только) удивление, когда код отработал без ошибок — счастливо избежав и E_RPC_TIMEOUT и E_RPC_DISCONNECT! Причем на той самой Windows 8.1, где воспроизведение проблемы было стопроцентным.

Workaround как бы найден, но он ничего не объясняет. Да и найден он только потому, что в те времена, когда я был юниором, конструкций foreach не было, и вместо осознанного действа я всего лишь потрафил своим мерзким олдскульным привычкам…

Вечер перестает быть томным

Возвращаемся к оригинальному foreach, дело все-таки где-то тут. Перехожу к гипотезе что все-таки что-то не то с нашим ком объектом. Добавляю пару косметических строк — для удобства отладки:

...
    var assetsCollection = lib.Assets;
    foreach(var asset in assetsCollection) {
        /* some long operations */
    }
    assetsCollection = null;
...

Как бы очевидно, что вот эти две строчки

...
    var assetsCollection = lib.Assets;
    ...
    assetsCollection = null;
...

вокруг цикла ни на что не влияют, правда? Зато брякпоинты на них ставить очень удобно.

Ставлю, бряк-бряк, запускаю, тынц-тынц, читаю хабру те 20 минут пока оно жует те ассеты. Не упало. Э?

А, наверное отладчик помешал, догадался Зоркий Глаз. Не меняя ничего запускаю без отладки. Не упало. Sorry what? Еще шесть запусков с каждой реализацией и каждым интеропом — показывают что древний код мамонта снова работает как и ранее — везде. Да, я его поправил 16 раз ;-)

А теперь — горбатый!

Казалось бы — и в чем же разница?

Давайте вспомним такой набор фактов:

• Кроме непосредственно нашего болеющего кода есть еще и garbage collector;
• Вокруг COM у нас прокси;
• Этот прокси за нас прячет AddRef()/Release();
• В классической реализации в Release() обычно присутствует if(count ==0) delete this; на стороне COM server:
• Для нашего ком прокси (который нечто отнаследованное от MarshalByRefObject), при приходе горбатого коллектора позовут Dispose(), а в нем таки дернут наш Release().

Вот теперь уже мы можем предположить — что же не так.

Очевидно, наш lib.Assets вычисляется один раз и более нигде не используется. Значит, заботливый компилятор этот факт отмечает сразу после первого цикла, где мы коллекцию ассетов в лист складываем.

И далее уже в нашем методе — коллектор может подобрать ту ссылку в любой момент, а то что метод работает очень долго — эту вероятность увеличивает практически до ста процентов. А вот child items очевидно — value objects с lazy initialization, и что они и как хранят внутри — можем только гадать. Ведь вовсе не следует что каждый айтем вызывает AddRef() когда попало. Я бы даже предположил — что гарантированно не. Ибо при написании ком сервера (который вызывается откуда угодно) ожидать что мастер-коллекции скаждут Release() и продолжат использовать child elements, часть из которых останется uninitialized… Странный паттерн.

А вот добавив две «незначащие» строчки — я как бы явно дал понять компилятору что это локальная переменная, которая живет от начала объявления до конца функции, и сборка ее гарантированно начнется не ранее чем «за последним использованием».

А при чем тут Windows 8.1? А при дотнете версии 4.5. Чуть более агрессивная сборка мусора по умолчанию — и вот оно.

Эту гипотезу я даже проверил — повторив тот же эффект с Windows 2012R2 / .NET 4.5 64bit, взяв для проверки AWS t2.micro instance. Причем E_RPC_DISCONNECT там прибежал значительно быстрее чем на препарируемой системе, так что что-то в этом есть.

Впрочем это все же умствования из области послезнания, возможно тут есть и другие факторы.

Автор: viklequick

Источник