Bug 10154

Summary: 'numfile' counter leak on HN
Product: Sisyphus Reporter: Nikolay A. Fetisov <naf>
Component: kernel-image-ovz-smpAssignee: Evgeny Sinelnikov <sin>
Status: CLOSED FIXED QA Contact: qa-sisyphus
Severity: critical    
Priority: P2 CC: alb, aspsk, boris, boyarsh, dev, glebfm, ildar, ldv, mike, mithraen, rider, sbolshakov, shrek, sin, vitty, vsu, vvk, vyt, zerg
Version: unstable   
Hardware: all   
OS: Linux   

Description Nikolay A. Fetisov 2006-10-18 17:38:34 MSD
В ядрах kernel-image-ovz-smp-2.6.16-alt7 как для i586, так и для x86_64 
наблюдается увеличение значения счётчика открытых файлов numfile для Hardware 
Node.
По-видимому, при закрытии файлов счётчик не уменьшается.

Параллельно с numfile увеличивается значение счётчика kmemsize.
При достаточно интенсивной работе на i586 kmemsize быстро достигает барьера в 
2^31, что приводит к необходимости перезагрузки HN.
Steps to Reproduce:
# watch "head -n 25 /proc/user_beancounters | egrep '(kmemsize|numfile)'"
Comment 1 Alex Moskalenko 2006-10-19 21:45:32 MSD
Действительно воспроизводится на
[root@test vz]# uname -a
Linux test.localdomain 2.6.16-ovz-smp-alt7 #1 SMP Thu Sep 28 12:55:15 MSD 2006 
i686 GNU/Linux
[root@test vz]# rpmquery -a | grep vz
vzctl-3.0.11-alt2
kernel-image-ovz-smp-2.6.16-alt7
vzquota-3.0.8-alt1
[root@test vz]# cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 15
model           : 2
model name      : Intel(R) Pentium(R) 4 CPU 2.40GHz
stepping        : 7
cpu MHz         : 2394.219
cache size      : 512 KB
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca cmov 
pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe cid xtpr
bogomips        : 4796.94
[root@test vz]# free
       total       used       free     shared    buffers     cached
Mem:        247464     242700       4764          0      25752      50872
-/+ buffers/cache:     166076      81388
Swap:       248968     101236     147732
[root@test vz]# uptime
 16:13:40 up 20 days,  1:25,  1 user,  load average: 0.10, 0.12, 0.09

Имеем следующую картину
[root@test vz]# head -n 25 /proc/user_beancounters | egrep '(kmemsize|
numfile)'
         0: kmemsize      563042756  563942030 2147483647 2147483647          
0
            numfile         2735509    2735509 2147483647 2147483647          
0

Счетчики на HN только увеличиваются...

Comment 2 Sir Raorn 2006-10-19 22:20:28 MSD
В alt4 всё работает, на alt7 подтверждаю такое поведение.
Comment 3 Dmitry V. Levin 2006-10-22 14:47:22 MSD
Reassigned to maintainer.
Comment 4 Dmitry V. Levin 2006-10-25 02:08:05 MSD
Похоже что alt4, будучи пересобранным в среде текущего Сизифа, начинает вести
себя так же как и alt7.
Comment 5 Konstantin A Lepikhov (L.A. Kostis) 2006-10-26 01:42:44 MSD
Вопроизводится с 026test020. Похоже, это бага все-таки в ovz патче. Думаю, багу
следует перевесить в bugzilla.openvz.org.
Comment 6 Konstantin A Lepikhov (L.A. Kostis) 2006-10-26 01:59:34 MSD
Если все-таки подождать чуть подольше, счетчик иногда уменьшается. Надо будет
промониторить его-чем нить.
Comment 7 Dmitry V. Levin 2006-10-26 02:21:05 MSD
Да, счётчик со временем немного уменьшается, но запаздывание этого уменьшения
таково, что регулярное открытие/закрытие файлов приводит к неудержимому росту
счётчика.

Между прочим, похожее запаздывание уменьшения счётчика заметно и в VE, легко
воспроизводится при использовании hasher внутри VE при относительно небольшом
значении лимита numfile (например, 4096).  Но в случае с VE запаздывание
уменьшения счётчика всё же значительно меньше чем в HN.
Comment 8 Sergey Vlasov 2006-10-27 16:58:57 MSD
(In reply to comment #4)
> Похоже что alt4, будучи пересобранным в среде текущего Сизифа, начинает вести
> себя так же как и alt7.
Это давно известная багофича нашей системы сборки ядер - если собирается старое
ядро, но при этом доступен репозиторий, где лежат более свежие пакеты с патчами,
будут использованы именно новые версии патчей. Нужно либо цеплять старый
репозиторий, либо собирать пакеты скриптами из kernel cvs (без использования
hasher).

(In reply to comment #7)
> Да, счётчик со временем немного уменьшается, но запаздывание этого уменьшения
> таково, что регулярное открытие/закрытие файлов приводит к неудержимому росту
> счётчика.

На самом деле с последней версией патча openvz (ну или хотя бы с
2.6.16-026test019) рост в конце концов должен прекратиться:

http://git.openvz.org/?p=linux-2.6.16-openvz;a=commitdiff;h=4165f1fa371b60cb3a225910faebde95650a1f65

Вообще данная проблема вызвана не совсем правильно работающей оптимизацией
ограничения на количество открытых файлов. Чтобы при каждом открытии и закрытии
файла не модифицировать счётчик в beancounter (и не захватывать при этом
spinlock), в ub_file_charge() и ub_file_uncharge() реализован механизм
precharge: при необходимости открытия новых файлов в ub_file_precharge()
запрашивается более одного дескриптора, при этом неиспользованные дескрипторы
учитываются в current->task_bc.file_precharged; ub_file_uncharge() по
возможности старается возвращать дескрипторы именно в file_precharged, а не в
beancounter. Этот механизм работал нормально в ядре 2.6.9, где при закрытии
файла вызов ub_file_uncharge() чаще всего происходил в контексте процесса,
вызвавшего close(). Однако в ядре 2.6.16 для struct file используется отложенное
освобождение через RCU, в результате вызов ub_file_uncharge() из file_free_rcu()
может происходить в контексте совершенно другого процесса, в результате счётчик
->task_bc.file_precharged может увеличиваться для тех процессов, которым это
совершенно не нужно (в частности, я подозреваю, что эти файлы может получить
даже idle task). Эти файлы будут "потеряны" с точки зрения numfile до тех пор,
пока в ub_file_uncharge() не перестанут выполняться оба условия:

                if (ub_barrier_farnr(pub, UB_NUMFILE) &&
                                ub_barrier_farsz(pub, UB_KMEMSIZE))
                        return;
                if (task_bc->file_precharged < (1UL << task_bc->file_quant))
                        return;

В первом условии проверяется, что лимиты numfile и kmemsize достаточно далеки от
исчерпания (использовано менее 1/8 лимита). Поскольку для HN лимиты выставлены в
LONG_MAX, ждать этого придётся довольно долго. (До 2.6.16-026test019 вторая
половина этого условия отсутствовала, именно это и приводило к необходимости
перезагрузки HN - лимит kmemsize кончался задолго до 1/8 * LONG_MAX для numfile).

Во втором условии проверяется количество сохранённых дескрипторов для текущего
процесса - если их слишком много, часть из них будет освобождена.

Т.е., для освобождения дескрипторов, залипших где-нибудь в idle task или в
длительно работающем процессе, который не закрывает файлы, нужно, чтобы эти
дескрипторы вместе с прочими ресурсами заняли не менее 1/8 kmemsize (либо 1/8
numfile), и при освобождение struct file через RCU произошло бы в контексте
процесса, куда ранее попали эти дескрипторы.
Comment 9 Sergey Vlasov 2006-10-27 17:12:01 MSD
Вообще получается, что при освобождении struct file через RCU механизм precharge
работает совершенно неправильно - при закрытии файлов их может получить в
->task_bc.file_precharged совершенно другой процесс (правда, обязательно из того
же VE - если VE не совпадает, ресурсы в beancounter освобождаются немедленно).
Что можно с этим сделать (помимо игнорирования проблемы):

1) Очевидный вариант - отключить эту оптимизацию совсем; в результате значение
счётчика numfile будет отражать реальную ситуацию, но при большом количестве
операций с файлами резко увеличится использование ub->ub_lock.

2) Вероятно, можно перенести вызов ub_file_uncharge() из file_free_rcu() в
file_free() - в этом случае file_precharged будет увеличиваться в нужном
процессе, но до реального освобождения структур file в file_free_rcu() может
пройти некоторое время, в течение которого эти структуры не будут учитываться в
numfile и kmemsize.
Comment 10 Dmitry V. Levin 2006-10-28 01:35:39 MSD
Кирилл, вы не могли бы прокомментировать эту проблему?
Comment 11 Pavel Emelianov 2006-10-30 11:27:53 MSK
Сергей Власов нашел правильный патч и объяснение того, что происходит.

Всвязи с тем, что файлы освобождаются через RCU, механизм не стал работать 
неправильно, просто если раньше освобождение файлов в контексте "чужого" 
процесса происходило _крайне_ редко (но все же происходило), то сейчас эта 
ситуация стала нормальной.

Насчет предложений как можно эту ситуацию улучшить могу сказать следующее.
1) отключение оптимизации - это выход, но, конечно, неприемлемый.
2) перенос ub_file_uncharge() в file_free() лишь растянет процесс роста 
счетчика, поскольку file_free() все-таки может случиться в контексте любого 
процесса, хотя и гораздо реже чем в случае с RCU.

По поводу "залипания" дескрипторов на процессах, которые не используют файлы. 
Для этого есть file_quant, который отражает насколько сильно процессу нужны 
файлы. Для процессов таких как init или демоны, которым файлы обычно не нужны, 
эта величина будет ~4, то есть больше чем 16 файлов на них не задержится.

С найденным патчем проблема, вообще говоря, исчезает - счетчик перестает 
неограниченно расти. Меняется смысл numfile ресурса. Если раньше он показывал 
реальное количество открытых файлов, то теперь это лишь верхняя оценка этого 
числа, причем чем выше limit тем оценка грубее.
Comment 12 Sergey Vlasov 2006-10-30 13:40:23 MSK
(In reply to comment #11)
> По поводу "залипания" дескрипторов на процессах, которые не используют файлы. 
> Для этого есть file_quant, который отражает насколько сильно процессу нужны 
> файлы. Для процессов таких как init или демоны, которым файлы обычно не нужны, 
> эта величина будет ~4, то есть больше чем 16 файлов на них не задержится.

file_quant не проверяется, пока лимит не будет выбран на 1/8, поэтому залипнет
заметно больше, чем 16 файлов. Возможно, стоит поменять условия освобождения,
чтобы файлы не накапливались.
Comment 13 Pavel Emelianov 2006-10-30 14:24:39 MSK
(In reply to comment #12)
> (In reply to comment #11)
> > По поводу "залипания" дескрипторов на процессах, которые не используют 
файлы. 
> > Для этого есть file_quant, который отражает насколько сильно процессу нужны 
> > файлы. Для процессов таких как init или демоны, которым файлы обычно не 
нужны, 
> > эта величина будет ~4, то есть больше чем 16 файлов на них не задержится.
> 
> file_quant не проверяется, пока лимит не будет выбран на 1/8, поэтому залипнет
> заметно больше, чем 16 файлов. Возможно, стоит поменять условия освобождения,
> чтобы файлы не накапливались.

Имелось в виду, что так будет после того, как выберут 1/8. После этого с 
процесса снимут
         nr = task_bc->file_precharged
                        - (1UL << (task_bc->file_quant - 1));

Возможно условие освобождения стоит сменить.
Comment 14 Nikolay A. Fetisov 2006-11-06 03:04:48 MSK
Поставил 2.6.16-ovz-smp-alt10. 

numfile неограниченно расти перестал, однако на 2хPIII где-то через 8 часов 
работы получил следующее в syslog:

-----------
Nov  5 17:50:01 naf177 kernel: Uncharging too much 2147915339 h 1431728, res 
numfile ub 0
Nov  5 17:50:01 naf177 kernel: Uncharging too much 2221302809 h 268646595, res 
kmemsize ub 0
Nov  5 17:50:01 naf177 kernel: UB: Bad refcount (-2146297003) on put of 0 
(c0380e00)
Nov  5 17:50:01 naf177 kernel: UB: Bad refcount (-2146297004) on put of 0 
(c0380e00)
Nov  5 17:50:01 naf177 kernel: UB: Bad refcount (-2146297005) on put of 0 
(c0380e00)
Nov  5 17:50:01 naf177 kernel: Uncharging too much 15 h 0, res numfile ub 0
Nov  5 17:50:01 naf177 kernel: Uncharging too much 23119 h 0, res kmemsize ub 0
Nov  5 17:50:01 naf177 kernel: UB: Bad refcount (-2146297021) on put of 0 
(c0380e00)
...... <и ещё примерно 60 Mb подобных сообщений за 2 часа> .....
-------------

Целенаправлено система убивается где-то часа за два, запуском в HN
$ while ((1)); do ls / &>/dev/null; done

При этом до граничных значений kmemsize не доходит,
 0: kmemsize      218197152  268631574 2147483647 2147483647          0
    numfile         1276733    1568970 2147483647 2147483647          0

Comment 15 Pavel Emelianov 2006-11-07 11:19:23 MSK
(In reply to comment #14)
Это уже выявлено. Скоро будет патч.
http://bugzilla.openvz.org/show_bug.cgi?id=322
Comment 16 Alexey Borovskoy 2006-11-08 06:26:54 MSK
Это уже пофиксили.

--- кусь ---
[UBC] Set correct precharge values for init_task.

Otherwise file freeing will happen in "swapper" context
and will spoil all statistics due to "negative" unsigned
long value.
---кусь---

http://bugzilla.openvz.org/show_bug.cgi?id=322
Описание проблемы.

http://git.openvz.org/?p=linux-2.6.16-openvz;a=commit;h=46d1e25bce7440b23652caf7f463670a5360890a
Патч.

Жду новую сборку на тестирование. :-)
Comment 17 Konstantin A Lepikhov (L.A. Kostis) 2006-11-08 10:49:04 MSK
(In reply to comment #16)
> Это уже пофиксили.
> 
> --- кусь ---
> [UBC] Set correct precharge values for init_task.
...
> Жду новую сборку на тестирование. :-)
kernel-feat-core-openvz с этим патчем лежит в cvs со вчерашнего дня. Сборку
нового ovz-smp блокирует сломанный feat-fs-squashfs, впрочем, я его скорее всего
выкину.
Comment 18 ildar 2006-12-12 12:01:59 MSK
# uname -r
2.6.18-ovz-smp-alt3
# ls /proc/*/fd | wc -l
5563
# less /proc/user_beancounters
       uid  resource           held    maxheld    barrier      limit    failcnt
        0:  kmemsize      196662888  197263647 2147483647 2147483647          0
            numfile          914996     914996 2147483647 2147483647          0

Как же так? :(
Comment 19 ildar 2006-12-20 14:04:12 MSK
Поправляю сам себя: бин-счётчики так же и ведут себя, как сумасшедшие, однако
это уже не столь фатально для хост-машины. В общем, однозначно советую
переходить на новое, 2.6.18-ovz-smp-alt3
Comment 20 Konstantin A Lepikhov (L.A. Kostis) 2007-04-06 00:33:16 MSD
Кто что может сказать о текущем положении дел? У меня пока эта ошибка ни разу не
воспроизвелась.
Comment 21 Vladimir V. Kamarzin 2007-04-06 08:19:19 MSD
На 2.6.18-ovz-smp-alt8 и 2.6.16-ovz-smp-alt12 описанной проблемы не наблюдаю.
Comment 22 Nikolay A. Fetisov 2007-04-06 09:12:45 MSD
Наверное, имеет смысл закрыть этот вопрос. Значения счётчиков остаются далёкими 
от действительности (во всяком случае, на одной из машин сейчас у меня 
numfile(HN) < summ numfile(VPS) ), но жить это не мешает. 
Comment 23 Kirill Korotaev 2007-04-06 17:12:28 MSD
1. Nikolay, я не понял замечания про "numfile(HN) < summ numfile(VPS)".
numfile(HN) - это те файлы что использует VE0. поэтому они никак не связаны с
VPS'ами...

2. В 2.6.18 проблема пофикшена. uncharge перенесен из RCU в file_free().

т.е. вроде бы можно закрывать.
Comment 24 Konstantin A Lepikhov (L.A. Kostis) 2007-04-06 23:55:30 MSD
Пока закрываю. Если что, опять откроем ;)

PS Кирилл, Сергей, спасибо за вашу помощь в выяснении причины проблемы.
PPS 2All Спасибо за проявленное терпение в поиске причин ошибки и отслеживания
ее статуса.