Bug 19331

Summary: Похоже сломана работа таймеров с созданием потока в качестве уведомления.
Product: Branch 5.0 Reporter: Roman Savochenko <rom_as>
Component: glibcAssignee: Dmitry V. Levin <ldv>
Status: RESOLVED LATER QA Contact: qa-5.0 <qa-5.0>
Severity: critical    
Priority: P4 CC: evg
Version: unspecified   
Hardware: all   
OS: Linux   
Attachments:
Description Flags
Архиватор значений none

Description Roman Savochenko 2009-03-25 19:00:46 MSK
Имеется многопоточная софтина openscada, которая создаёт потоки по таймеру.
Таймер создаётся кодом:
struct sigevent sigev;
memset(&sigev,0,sizeof(sigev));
sigev.sigev_notify = SIGEV_THREAD;
sigev.sigev_value.sival_ptr = this;
sigev.sigev_notify_function = Task;
sigev.sigev_notify_attributes = NULL;
int rez = timer_create(CLOCK_REALTIME,&sigev,&tmId);
printf("Create timer: '%s' %d(%d)\n",id().c_str(),tmId,rez);

Удаляется:
int rez = timer_delete(tmId);
printf("Delete timer: '%s' %d(%d)\n",id().c_str(),tmId,rez);

Падение происходит секунды через 2 после вызова timer_delete:
Create timer: '1m' 137099560(0)
Create timer: '1s' 134604544(0)
Delete timer: '1m' 137099560(0)
./openscada_demo: line 3: 12837 Segmentation fault

При этом таймер я даже не запускаю и вызов в функцию Task не приходит, а просто создаю и удаляю таймер. gdb сообщает примерно о таком:
(gdb) bt
#0  0xb7c774c0 in pthread_cancel () from /lib/librt.so.1
#1  0xb7c85daa in start_thread () from /lib/libpthread.so.0
#2  0xb7d63f4e in clone () from /lib/libc.so.6

Пытался воспроизвести на макете с созданием и удалением таймера из одного потока, но там это не воспроизвелось. Или оказывает влияние на это большое количество потоков исполняемых параллельно, но независимо, или создавать и удалять таймера в разных потоках нельзя, чего в документации я не встречал.

P.S. Кроме этого момента таймера работают нормально. А именно запускаются и останавливаются включая и из разных потоков. Процедура по таймеру корректно вызывается.
Comment 1 Roman Savochenko 2009-03-25 19:39:58 MSK
Похоже в glibc проблемы с разделением доступа к общим данным таймеров и/или потоков.
Остановил высоконагруженные потоки с периодичностью 5мс и общей нагрузкой процессора 40%(2ГГц) и таймера нормально поудалялись!
Т.е причина не удаление в другом потоке, а проблема совместных ресурсов в GlibC.
Кроме того на Branch4.1 x86_64 с kernel-2.6.18ovz у которого нет поддержки времени высокого разрешения и разрешение таймера 4мс, все таймера корректно удалились.
Comment 2 Roman Savochenko 2009-03-25 20:02:10 MSK
Повышаю приоритет ошибки.
Comment 3 Roman Savochenko 2009-03-25 22:08:20 MSK
На kernel-2.6.25 и glibc-2.5.1 из Branch 4.0 эта проблема ещё не проявляется.
Тестил на ноуте в той-же конфигурации и полной загрузкой CPU тем-же источником. Ядро уже держит высокое разрешение времени.
Comment 4 Roman Savochenko 2009-03-26 11:25:01 MSK
С компилятором, которым собирается программа, проблема не связана. Собрал gcc-4.3, gcc-4.1 и gcc-3.4, результат идентичен:
(gdb) bt
#0  0xb7ba64c0 in __gxx_personality_v0 () from /lib/librt.so.1
#1  0xb7bafdaa in start_thread () from /lib/libpthread.so.0
#2  0xb7c92f4e in clone () from /lib/libc.so.6
Comment 5 Roman Savochenko 2009-03-26 12:15:37 MSK
На SuSE 11.1 с glibc-2.9-2.11.1 - проблема не обнаружена
На Mandriva 2009.0 с glibc-2.8-1.20080520.5.2mnb2 - проблема проявляется:
(gdb) bt
#0  0xb7b249b0 in ?? () from /lib/i686/librt.so.1
#1  0xb7b2723c in ?? () from /lib/i686/librt.so.1
#2  0x086c5178 in ?? ()
#3  0xb7b24a30 in ?? () from /lib/i686/librt.so.1
#4  0x08a5bf48 in ?? ()
#5  0x00000000 in ?? ()
Comment 6 Roman Savochenko 2009-03-26 16:02:01 MSK
Пересобрал glibc-2.9-alt4 из Сизифа для Branch 5.0 - проблема не исправилась.
Comment 7 Roman Savochenko 2009-03-27 13:43:20 MSK
Branch 4.1 glibc-core-2.5.1-alt4 - проблема не проявляется.
Comment 8 Dmitry V. Levin 2009-03-30 19:33:54 MSD
Роман, спасибо.  Можно приложить сюда код, поведение которого изменилось?
Comment 9 Roman Savochenko 2009-03-30 20:01:27 MSD
Created attachment 3419 [details]
Архиватор значений

Пожалуйста.
Вкладываю файл части исходника проекта OpenSCADA. Только искать там можно долго. Проблемные участки это конструктор и деструктор класса TVArchivator:
TVArchivator::TVArchivator( const string &iid, const string &idb, TElem *cf_el ) : run_st(false), prc_st(false),
    tm_calc(0.0), TConfig(cf_el), m_db(idb), m_id(cfg("ID").getSd()), m_name(cfg("NAME").getSd()),
    m_dscr(cfg("DESCR").getSd()), m_addr(cfg("ADDR").getSd()), m_start(cfg("START").getBd()),
    m_v_per(cfg("V_PER").getRd()), m_a_per(cfg("A_PER").getId())
{
    m_id = iid;

    //> Create calc timer
    struct sigevent sigev;
    memset(&sigev,0,sizeof(sigev));
    sigev.sigev_notify = SIGEV_THREAD;
    sigev.sigev_value.sival_ptr = this;
    sigev.sigev_notify_function = Task;
    sigev.sigev_notify_attributes = NULL;
    timer_create(CLOCK_REALTIME,&sigev,&tmId);
}

TVArchivator::~TVArchivator()
{
    timer_delete(tmId);
}

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

И если timer_delete(tmId); закомментировать, то проблема не возникает, но естественно текут ресурсы таймера.

Вообще была мысль попробовать в макет добавить с десяток потоков с имитацией рабочей нагрузки, что-бы оно проявлялось более отчётливо.
Comment 10 Roman Savochenko 2009-05-14 13:46:43 MSD
Valgrind по поводу timer_delete() постоянно сообщает такое:
==21938==
==21938== Conditional jump or move depends on uninitialised value(s)
==21938==    at 0x4417324: timer_delete (in /lib/librt-2.9.so)
==21938==    by 0x405C905: TArchiveS::~TArchiveS() (in /mnt/home/roman/work/OScadaD/lib/liboscada.so.0.0.10)
Comment 11 Dmitry V. Levin 2009-06-18 01:22:45 MSD
Боюсь что я не готов отлаживать большую и сложную программу из проекта OpenSCADA.
К сожалению, апстрим этого тоже не станет делать, для этого нужен test case попроще.
Comment 12 Roman Savochenko 2009-06-18 10:14:41 MSD
У меня не получилось добиться повторения на тестовом прототипе, даже добавив близкую нагрузку. Похоже сказывается достаточно специфичная нагрузка. Кроме того, в компоненте где ошибка проявлялась я перешёл на независимые потоке, по объективным причинам.

Поэтому откладываем на позже, может у кого такое ещё вылезет.
Comment 13 Roman Savochenko 2009-07-10 12:10:10 MSD
glibc-2.10.1-alt4
Valgrind по прежнему указывает на наличие проблемы в функции timer_delete:
==5608== Thread 1:                                                                   
==5608== Conditional jump or move depends on uninitialised value(s)                  
==5608==    at 0x442BF72: timer_delete (in /lib/librt-2.10.1.so)                     
==5608==    by 0x6AE9FD7: FSArch::ModArch::~ModArch() (in /mnt/home/roman/work/OScadaD/lib/openscada/arh_FSArch.so)
==5608==    by 0x41343FD: TCntrNode::chldDel(char, std::string const&, long, int, bool) (in /mnt/home/roman/work/OScadaD/lib/liboscada.so.0.0.10)
==5608==    by 0x40DB504: TSubSYS::modDel(std::string const&) (in /mnt/home/roman/work/OScadaD/lib/liboscada.so.0.0.10)
==5608==    by 0x411A4F6: TModSchedul::preDisable(int) (in /mnt/home/roman/work/OScadaD/lib/liboscada.so.0.0.10)
==5608==    by 0x41336D6: TCntrNode::nodeDis(long, int) (in /mnt/home/roman/work/OScadaD/lib/liboscada.so.0.0.10)
==5608==    by 0x41344BA: TCntrNode::chldDel(char, std::string const&, long, int, bool) (in /mnt/home/roman/work/OScadaD/lib/liboscada.so.0.0.10)
==5608==    by 0x4050525: TSYS::~TSYS() (in /mnt/home/roman/work/OScadaD/lib/liboscada.so.0.0.10)
==5608==    by 0x8048D3A: main (in /mnt/home/roman/work/OScadaD/bin/openscada)