ALT Linux Bugzilla – #19364

Created attachment 3402 [details]
Вывод dmesg до запуска обмена

Created attachment 3403 [details]
Вывод dmesg после запуска обмена и SysRq-P

Created attachment 3404 [details]
Вывод dmesg после запуска обмена и SysRq-T

Created attachment 3405 [details]
Вывод lspci -vvnn

Created attachment 3406 [details]
Список загруженных модулей

Created attachment 3407 [details]
Вывод top при обмене

Created attachment 3408 [details]
Устройства в /dev/inputs/by-path

Created attachment 3409 [details]
сообщение о soft lockup

После появления этого сообщения компьютер становится неуправляемым и откликается только на Reset.

(В ответ на комментарий №3)
> Created an attachment (id=3404) [details]
> Вывод dmesg после запуска обмена и SysRq-T

Придётся загрузиться с параметром log_buf_len=1M и повторить ещё раз - данные для процесса events/0 не влезли в буфер.

Исходники программы transmitter у вас есть?  Вызывает подозрение следующий фрагмент:

[  855.920003] transmitter   R running      0  8273      1
[  855.920003]        f2ddbf18 c0465911 c0246795 f2ddbf44 00000000 c19121a0 f2ddbf44 f2ddbf44 
[  855.920003]        c1912228 c1912220 f2ddbee0 f7892000 f788aec0 c0605080 f26a2130 f26a23a0 
[  855.920003]        c1915080 00000001 00000282 c1915080 4a07a6e2 f2ddbf44 000000c7 f26a23a0 
[  855.920003] Call Trace:
[  855.920003]  [<c0246795>] ? hrtimer_reprogram+0x85/0xc0
[  855.920003]  [<c0466926>] do_nanosleep+0x86/0xc0
[  855.920003]  [<c02472d8>] hrtimer_nanosleep+0x98/0x110
[  855.920003]  [<c0246ba0>] ? hrtimer_wakeup+0x0/0x20
[  855.920003]  [<c0466913>] ? do_nanosleep+0x73/0xc0
[  855.920003]  [<c02473b0>] sys_nanosleep+0x60/0x70
[  855.920003]  [<c0203e72>] syscall_call+0x7/0xb

(При отсутствии исходников можно посмотреть туда strace -p)

Если там в цикле вызывается nanosleep() с достаточно малой задержкой, возможно, при переходе на новые ядра с поддержкой highres timers происходит существенное изменение поведения - раньше таймаут для обычных процессов (не realtime) фактически увеличивался до значения, кратного 1/HZ (в конфигурации ядер std HZ==250), а в новых ядрах малые задержки обрабатываются с существенно большей точностью, что может приводить к резкому росту потребления процессорного времени, если программа использует nanosleep() с малыми задержками.  В 2.6.28 аналогичный переход на hrtimer произойдёт и для системных вызовов select() и poll().  Можно попробовать загрузку с параметром highres=0 - в этом случае в ядре будет использоваться старый режим работы с таймерами.

Попробую уже на следующей неделе. transmitter - это моя программа, но она сама не использует nanosleep, только poll (в виде poll (&poller, 1, 1000); ), максимум usleep(1), но это только для ожидания клавиатуры в одном из потоков и более ничего.

Вот ещё возможный кусок:

clock_gettime (CLOCK_REALTIME, &timeToWait);
        timeToWait.tv_nsec += 20000000;
clock_gettime (CLOCK_REALTIME, &timeToWait);
        timeToWait.tv_nsec += 20000000;

        if (timeToWait.tv_nsec >= 1000000000) {
            timeToWait.tv_nsec -= 1000000000;
            timeToWait.tv_sec++;
        }

        ret = sem_timedwait (&semSend, &timeToWait);

        if (timeToWait.tv_nsec >= 1000000000) {
            timeToWait.tv_nsec -= 1000000000;
            timeToWait.tv_sec++;
        }

        ret = sem_timedwait (&semSend, &timeToWait);

Или:
    tv.it_interval.tv_sec = 0;
    tv.it_interval.tv_usec = 60000;
    tv.it_value.tv_sec = 0;
    tv.it_value.tv_usec = 60000;
    setitimer (ITIMER_REAL, &tv, NULL);

Больше нигде я не играюсь с таймерами.

Кстати, именно работа программы transmitter (которая и обменивается с Moxa), вешает всё. Но как? вживую (strace или ptrace) подключиться практически невозможно, так как она уходит на realtime=10:

    s_par.sched_priority = 10;
    sched_setscheduler (0, SCHED_FIFO, &s_par);

для обеспечения точности в интервалах передачи данных в аппаратуру через Moxa.

(В ответ на комментарий №10)
> Попробую уже на следующей неделе. transmitter - это моя программа, но она сама
> не использует nanosleep, только poll (в виде poll (&poller, 1, 1000); ),
> максимум usleep(1), но это только для ожидания клавиатуры в одном из потоков и
> более ничего.

Функция usleep() в текущих версиях glibc превращается в системный вызов nanosleep; вероятнее всего, это как раз тот самый поток.  Если там в коде что-то типа

	for (;;) {
		if (input_available())
			handle_input();
		usleep(1);
	}

(да ещё и с realtime-приоритетом) - это очень плохо, и как раз будет вызывать огромную загрузку процессора (на E6750 usleep(1) в цикле сжирает 30%, на чём-то более медленном будет больше).

(В ответ на комментарий №11)
> Вот ещё возможный кусок:
Тут задержки вменяемые - 20 мс и 60 мс.

Да, проблема оказалась именно в usleep(1). Когда всё стало вменяемо работать, то и данные тоже стали передаваться. Закрываю.