LINUX.ORG.RU

Почему может зависнуть вызов localtime()?

 ,


2

4

Есть такая замечательная софтина xrdp. И есть в ней такой замечательный код логгирования:

enum logReturns DEFAULT_CC
log_message(const enum logLevels lvl, const char *msg, ...)
{
    char buff[LOG_BUFFER_SIZE + 31]; /* 19 (datetime) 4 (space+cr+lf+\0) */
    va_list ap;
    int len = 0;
    enum logReturns rv = LOG_STARTUP_OK;
    int writereply = 0;
    time_t now_t;
    struct tm *now;

    if (g_staticLogConfig == NULL)
    {
        g_writeln("The log reference is NULL - log not initialized properly");
        return LOG_ERROR_NO_CFG;
    }

    if (0 > g_staticLogConfig->fd && g_staticLogConfig->enable_syslog == 0)
    {
        return LOG_ERROR_FILE_NOT_OPEN;
    }

    now_t = time(&now_t);
    now = localtime(&now_t);

Так вот, ИНОГДА, при неизвестных обстоятельствах, когда одновременно открывается много сессий, вызов now = localtime(&now_t); наглухо зависает. При этом bt в gdb показывает следующее:

(gdb) bt
#0  __lll_lock_wait_private () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:95
#1  0x00007f8a100bbabc in _L_lock_2480 () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x00007f8a100bb8f7 in __tz_convert (timer=0x7f8a103c9ee0 <tzset_lock>, use_localtime=1, tp=0x7f8a103ccde0 <_tmbuf>) at tzset.c:627
#3  0x00007f8a10a1441b in log_message (lvl=LOG_LEVEL_INFO, msg=0x7f8a10a1b180 "An established connection closed to endpoint: %s") at log.c:556
#4  0x00007f8a10a1532d in g_tcp_close (sck=9) at os_calls.c:678
#5  0x0000000000405976 in session_start_fork (width=1024, height=768, bpp=24, username=0x7f8a08004a30 "xxx", 
    password=0x7f8a08004a60 "xxx", data=140230816451248, type=1 '\001', domain=0x0, program=0x0, directory=0x0, 
    client_ip=0x7f8a08004a80 "123.0.0.123:59517 - socket: 9") at session.c:523
#6  0x0000000000406bc0 in session_sync_start () at session.c:907
#7  0x00000000004041a5 in sesman_main_loop () at sesman.c:100
#8  0x0000000000404a84 in main (argc=1, argv=0x7fff8cb123d8) at sesman.c:393
(gdb) 

Из-за чего это может быть (сразу скажу, что код в этом месте не многопоточный, хотя форкается куча процессов)?

Система - Ubuntu 14.04. xrdp - 0.9 из git master.

UPD:

(gdb) info threads 
  Id   Target Id         Frame 
* 1    Thread 0x7f891182f740 (LWP 13555) "xrdp-sesman" __lll_lock_wait_private () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:95
(gdb) 
★★★★★

Последнее исправление: asaw (всего исправлений: 2)
Ответ на: комментарий от asaw

Да, но что делать с вызовом syslog()?

Страдать, вот, например, еще один баг.
А если серьезно - то или выкинуть его тоже, или сделать свою localtime() и подгружать её.

joy4eg ★★★★★
()
Ответ на: комментарий от joy4eg

Кстати, сами же сигналы можно заблокировать, либо пользовать signalfd, который будет работать в текущем потоке, и не будет прерывать выполнение программы.

joy4eg ★★★★★
()
Ответ на: комментарий от asaw

вообще, логирование откуда попало (в том числе с вызовами функций работы с датами) - плохая идея. очереди сообщений и отдельный обработчик на высер всего накопленного в логи и т.д.

Iron_Bug ★★★★★
()
Ответ на: комментарий от Iron_Bug

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

asaw ★★★★★
() автор топика
Ответ на: комментарий от asaw

ну, для обычного приложения это так. но стоит хоть чуть-чуть отойти от массового программирования в сторону чего-то более замысловатого, и сразу уже приходится работать вручную. вообще, мы во всех проектах свои логгеры делали. это не так затратно, зато надёжно. а уж куда потом срать из лога - дело десятое. впрочем, можешь попробовать форкнуть syslog и решить проблему в корне :) я думаю, у них тоже были какие-то тараканы на этот счёт, раз они не стали обеспечивать абсолютную безопасность вызовов.

Iron_Bug ★★★★★
()
Вы не можете добавлять комментарии в эту тему. Тема перемещена в архив.