Регистрация...

Eserv Forum / E5 / Mail / Падение acIMAP

recent wikipost // (v1)
Продукты и услуги Скачать Документация Купить Поддержка Форумы Партнёрам Статьи О компании
После установки последнего обновления сервис acIMAP через некоторое время перестает отвечать с записью в лог следующего сообщения:

SUBSCRIBE FOLDER: &BCMENAQwBDsENQQ9BD0ESwQ1- &BE0EOwQ1BDwENQQ9BEIESw-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-
SUBSCRIBE FOLDER: &BCMENAQwBDsENQQ9BD0ESwQ1- &BE0EOwQ1BDwENQQ9BEIESw-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-

0 Message not found (FETCH) Exception time: Wed, 12 Mar 2014 13:24:41 +0400 Thread number/reuse/id:13 0 2052
API Calls: GetTickCount sqlite3_finalize

0 Message not found (FETCH) Exception time: Wed, 12 Mar 2014 13:24:41 +0400
Thread number/reuse/id:13 0 2052 API Calls: GetTickCount sqlite3_finalize

0 Message not found (FETCH) Exception time: Wed, 12 Mar 2014 13:36:54 +0400 Thread number/reuse/id:13 0 2052
API Calls: GetTickCount sqlite3_finalize

0 Message not found (FETCH) Exception time: Wed, 12 Mar 2014 13:36:55 +0400
Thread number/reuse/id:13 0 2052 API Calls: GetTickCount sqlite3_finalize

0 Message not found (FETCH) Exception time: Wed, 12 Mar 2014 13:36:55 +0400 Thread number/reuse/id:13 0 2052
API Calls: GetTickCount sqlite3_finalize

0 Message not found (FETCH) Exception time: Wed, 12 Mar 2014 13:36:56 +0400
Thread number/reuse/id:13 0 2052 API Calls: GetTickCount sqlite3_finalize

0 Message not found (FETCH) Exception time: Wed, 12 Mar 2014 14:04:32 +0400 Thread number/reuse/id:21 0 4484
API Calls: GetTickCount sqlite3_finalize

0 Message not found (FETCH) Exception time: Wed, 12 Mar 2014 14:04:33 +0400
Thread number/reuse/id:21 0 4484 API Calls: GetTickCount sqlite3_finalize

SUBSCRIBE FOLDER: &BCMENAQwBDsENQQ9BD0ESwQ1- &BE0EOwQ1BDwENQQ9BEIESw-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-2
SUBSCRIBE FOLDER: &BCMENAQwBDsENQQ9BD0ESwQ1- &BE0EOwQ1BDwENQQ9BEIESw-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-2
UNHANDLED EXCEPTION: FFFFFECA
RETURN STACK:
067BEF9C : 00555234 CATCH
067BEFA0 : 00000000
067BEFA4 : 067BFF80 UNHANDLED EXCEPTION: FFFFFECA
RETURN STACK:
05ABEF9C : 00555234
067BEFA8 : 0056B954 CATCH
05ABEFA0 : 00000000
05ABEFA4 : 05ABFF80 FATAL-HANDLER1
067BEFAC : 005551CC
05ABEFA8 : 0056B954 THROW
067BEFB0 : 00572CF5 FATAL-HANDLER1
05ABEFAC : 005551CC (")
067BEFB4 : 00553294 THROW
05ABEFB0 : 00572CF5 (LocalsExit)
067BEFB8 : 00000004
067BEFBC : 0000007B
(")
05ABEFB4 : 00553294 067BEFC0 : 005730C1 (LocalsExit)
05ABEFB8 : 00000004 _STRLITERAL
067BEFC4 : 005ED850
05ABEFBC : 0000007B
05ABEFC0 : 005730C1 CATCH
067BEFC8 : 005ED9D4 _STRLITERAL
05ABEFC4 : 005ED850 ClassicThread
067BEFCC : 005ED9E8 CATCH
05ABEFC8 : 005ED9D4 ClassicThread
SOURCE:
 
Комментарии к этой версии (13.03.2014 08:57) [~i.schelokov] 5fbfaef2
АвторДатаТекстtags
i.schelokov14.03.2014 08:39
ред: 14.03.2014 08:42
Сегодня в логе появились следующие записи:
SUBSCRIBE FOLDER: &BCMENAQwBDsENQQ9BD0ESwQ1- &BE0EOwQ1BDwENQQ9BEIESw-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-2
SUBSCRIBE FOLDER: &BCMENAQwBDsENQQ9BD0ESwQ1- &BE0EOwQ1BDwENQQ9BEIESw-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-2
SUBSCRIBE FOLDER: &BCMENAQwBDsENQQ9BD0ESwQ1- &BE0EOwQ1BDwENQQ9BEIESw-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-1
SUBSCRIBE FOLDER: &BCMENAQwBDsENQQ9BD0ESwQ1- &BE0EOwQ1BDwENQQ9BEIESw-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-1

0 Message not found (FETCH) Exception time: Thu, 13 Mar 2014 13:11:49 +0400 Thread number/reuse/id:26 0 5692
API Calls: GetTickCount sqlite3_finalize

0 Message not found (FETCH) Exception time: Thu, 13 Mar 2014 13:11:50 +0400
Thread number/reuse/id:26 0 5692 API Calls: GetTickCount sqlite3_finalize

PutMessage — error=-1073741811 uid=11469
SUBSCRIBE FOLDER: &BB4EQgQ,BEAEMAQyBDsENQQ9BD0ESwQ1-
SUBSCRIBE FOLDER: &BBoEPgRABDcEOAQ9BDA-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-
SUBSCRIBE FOLDER: &BB4EQgQ,BEAEMAQyBDsENQQ9BD0ESwQ1-
SUBSCRIBE FOLDER: &BBoEPgRABDcEOAQ9BDA-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-

PutMessage — error=-1073741811 uid=11479
SUBSCRIBE FOLDER: &BB4EQgQ,BEAEMAQyBDsENQQ9BD0ESwQ1-
SUBSCRIBE FOLDER: &BBoEPgRABDcEOAQ9BDA-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-
SUBSCRIBE FOLDER: &BB4EQgQ,BEAEMAQyBDsENQQ9BD0ESwQ1-
SUBSCRIBE FOLDER: &BBoEPgRABDcEOAQ9BDA-
SUBSCRIBE FOLDER: &BCcENQRABD0EPgQyBDgEOgQ4-
SUBSCRIBE FOLDER: &BB0ENQQ2BDUEOwQwBEIENQQ7BEwEPQQwBE8- &BD8EPgRHBEIEMA-

После чего служба продолжает работать, но новые письма клиентам не приходят. Помогает перезапуск службы acIMAP.
wikipost
ac14.03.2014 12:08
Если есть возможность поставить предыдущую версию acIMAP, то попробуйте пожалуйста, решит ли это проблему. Тогда будем точно знать, что дело именно последних правках.

Вообще эти "Message not found" были давно (это не exception на практике, просто используются те же функции для дампа состояния потока), и связаны с тем, что при одновременном подключении почтового клиента несколькими соединениями (или нескольких почтовых клиентов к одной папке) какие-то уведомления об удалении могли быть клиентом пропущены, и он запрашивает сообщение, которое уже было удалено в другом подключении. Возможно проблема бы решилась перезапуском почтового клиента, а не сервера. В последних версиях Outlook (2013 в частности) замечена проблема с неполучением писем (Outlook вообще перестаёт подключаться к серверу), не решаемая ни перезапуском Outlook, ни перезапуском сервера, а требует перезагрузки той клиентской машины, на которой это возникает. Я думаю, там дело в зависании какого-то системного компонента Windows, проверяющего SSL-сертификаты.
wikipost
i.schelokov14.03.2014 12:44
С предыдущей версией acIMAP попробую, а вот OUTLOOK в данном случае скорее всего не причем... т.к. его перезагрузка не требуется, да и телефон с андроидом то-же перестает получать почту...
wikipost
pig14.03.2014 14:08
В первом логе код -310, а это вроде как ошибка выделения памяти. Или на Message not found тот же код используется?
wikipost
i.schelokov14.03.2014 14:40
После замены acIMAP на старую версию в логе появились записи:
HEAP_SIZE
^ HEAP_SIZE
^ HEAP_SIZE
^ HEAP_SIZE
^ HEAP_SIZE
^ HEAP_SIZE
^ HEAP_SIZE
^ HEAP_SIZE
^

Но на работоспособности пока никак не сказывается.
wikipost
ac14.03.2014 18:39
Нет, -310 (UNHANDLED EXCEPTION: FFFFFECA) с Message not found скорее всего не связано. Там действительно что-то с хипом, и это как раз может быть искомой проблемой, в отличие от других (псевдо)exceptions — Message not found — которые в общем объяснимы, и не должны приводить к зависанию сервера.

Да, в старых версиях не было HEAP_SIZE, а в новых форматных строках используется. Можно в конце acIMAP\conf\OnStartup.rules.txt поставить
: HEAP_SIZE 0 ;
чтобы лог не засорялся.
wikipost
i.schelokov17.03.2014 10:29
В общем HEAP_SIZE я добавлять пока не стал, acIMAP работает стабильно с 14.03...
Единственное, в логе довольно много записей вида:
Message not found (FETCH) Exception time: Mon, 17 Mar 2014 10:22:52 +0400 Thread number/reuse/id:529 0 6072
API Calls: GetTickCount sqlite3_finalize

Message not found (FETCH) Exception time: Mon, 17 Mar 2014 10:22:52 +0400
Thread number/reuse/id:605 0 2416 API Calls: GetTickCount sqlite3_finalize

Message not found (FETCH) Exception time: Mon, 17 Mar 2014 10:22:53 +0400 Thread number/reuse/id:602 0 8028
API Calls: GetTickCount sqlite3_finalize

Message not found (EXPUNGE) Exception time: Mon, 17 Mar 2014 10:32:47 +0400
Thread number/reuse/id:615 0 6396 API Calls: GetTickCount sqlite3_finalize

На работоспособность они вроде не влияют, но раньше такого не было.
wikipost
i.schelokov19.03.2014 15:22
ред: 19.03.2014 15:23
Сегодня опять получили в логе ошибку:

PutMessage — error=-310 uid=6631

Wed, 19 Mar 2014 11:18:40 +0400 Can't create thread. Error:8
PutMessage — error=-310 uid=6631

и сервис перестал отвечать...

Причем произошла полная остановке сервиса acIMAP.
wikipost
ac20.03.2014 02:38
Это с предыдущей версией acIMAP?

А ошибка 8 — это исчерпание памяти.
wikipost
i.schelokov20.03.2014 11:11
ред: 20.03.2014 11:13
acIMAP проработал с 14.03 до 18.03 бес проблем, но я не вносил в acIMAP\conf\OnStartup.rules.txt ": HEAP_SIZE 0 ;"

После внесения этой строки acIMAP проработал чуть меньше суток и закрылся с ошибкой. На данный момент acIMAP еще работает, но уже занимает 828 Mb памяти.

Причем это все с предыдущей версией...

И еще в лог пишется очень много записей вида:

Message not found (FETCH) Exception time: Thu, 20 Mar 2014 12:07:04 +0400 Thread number/reuse/id:276 0 7652
API Calls: GetTickCount sqlite3_finalize
По несколько раз в минуту. Думаю, что это не нормально.
wikipost
pig20.03.2014 12:07
Конечно, ненормально. Это какой-то из клиентов хулиганит. Возможно, поэтому и память распределённая растёт — сессии не закрываются, новые открываются.
А упомянутая строка на выделение памяти не влияет вообще, это затычка, чтобы в логе не мусорилось. И не подхватывается до перезапуска acIMAP.
wikipost
ac20.03.2014 12:54
Да, если этих "Message not found" очень много, то это признак полного "рассинхрона" индекса сообщений в клиенте и сервере. Можно по логу вычислить, какой это клиент и пересоздать в нём (IMAP-клиенте) учетную запись, чтобы он заново скачал индекс.
wikipost
i.schelokov20.03.2014 15:28
А можно подсказать методику вычисления этого клиента? А то я не совсем понимаю как это сделать.
wikipost
ac20.03.2014 15:46
В строке "Message not found" указан номер потока, он также фигурирует и в логах IMAP и статистики. Соответственно там будет IP и логин.
wikipost
i.schelokov21.03.2014 13:59
Вычислил клиента, у которого поломался индекс.
Затем вернул последнюю версию acIMAP, буду наблюдать...
wikipost
alex112421.03.2014 20:56
А можно ли переиндексировать всех клиентов разом?
wikipost
ac25.03.2014 00:05
ред: 25.03.2014 00:06
Переиндексировать клиентов? Централизовано не получится — удаление несинхронной учетной записи на клиенте делается же.

Можно "намекнуть" IMAP-клиенту, чтобы он скачал индекс сообщений папки заново, сменив UIDVAL в .dirs.db3 (список пользовательских папок, UIDVAL там по умолчанию пустой, но можно установить любое число — это отразится в uid validity протокола IMAP), но, по-моему, в описанном выше случае это не поможет, так как он и так должен был "понять" по списку, что требуемые им сообщения уже удалены, а раз упорно требует выдать, значит "застряло" что-то в его локальной базе.
wikipost
i.schelokov25.03.2014 08:45
В общем с 21 числа acIMAP работает нормально, единственное используемая процессом память медленно, но растет... Если через сутки используемая процессом память была 44 Мб, то сегодня уже 477 Мб...
wikipost
pig25.03.2014 21:35
А другие счётчики? Хэндлы, потоки?
wikipost
i.schelokov27.03.2014 09:27
На данный момент количество используемой памяти 143532 кБ, потоков 23... так, что похоже, все в норме.
wikipost
v753box27.03.2014 10:14
ред: 02.04.2014 07:55
Удалено, вынес в отдельную тему
wikipost
pig27.03.2014 13:36
Давайте про это отдельную тему. А то теряется в общем потоке.
IMHO, по-разному стандарты трактуются. Надо воспроизводить ситуацию и ловить того дьявола, что в деталях кроется.
wikipost
Работает на Eserv/5.05567 (10.02.2020)