LINUX.ORG.RU

История изменений

Исправление PPP328, (текущая версия) :

Не совсем понял «вы можете вообще убрать это вызов» что вы имели в виду?

Окей, я имел в виду код вообще без аллокаций (на стороне кода).

Смотрите, разберем то, что вы хотите отправить:

[INFO]: [07/08/2024  13:35:26.286] Variable ENV_SUPERUSER is not set \n
^^^^^^
Тип сообщения
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
        Время/дата
                                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
                                   Сообщение с %s
                                                                     ^^
                                                                     Каретка

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

// Пишет в file тип сообщения и время
static void _log_file_wtime(FILE *file, enum log_level level) {
    struct timespec ts;
    clock_gettime(CLOCK_REALTIME, &ts); 
    struct tm *lt = localtime(&ts.tv_sec);

    fprintf(
        file,
        "[%s]: [%02d/%02d/%4d  %02d:%02d:%02d.%03d] ",
        _log_str_level(level),
        lt->tm_mday, 
        lt->tm_mon+1, 
        lt->tm_year+1900, 
        lt->tm_hour, 
        lt->tm_min, 
        lt->tm_sec, 
        (int)(1e-6*ts.tv_nsec)
    );
}

// Пишет в file переданные исходно данные
static void _log_file_wdata(FILE *file, const char *fmt, va_list args) {
    vfprintf(file, fmt, args);
}

// Пишет в file \n
static void _log_file_wlend(FILE *file) {
    fprintf(file, "\n");
}

И эти вызовы переезжают на замену вот этому: _log_file_write:

__attribute__((format(printf, 2, 3)) 
void log(enum log_level level, const char *fmt, ...) {

    va_list args;
    va_start(args, fmt);
    FILE *stdfile = _log_std_file(level);
    _log_file_whead(stdfile, level);
    _log_file_wdata(stdfile, fmt, args);
    _log_file_wlend(stdfile);
    va_end(args);


    static const char *log_env_file = "LOG_FILENAME";
    const char *filename = getenv(log_env_file);
    
    if (filename) {
        FILE *file = fopen(filename, "a");
        if (!file)
            // Ну вы тут сами обработку ошибок напишите, мне лень

        va_start(args, fmt);
        _log_file_whead(file, level);
        _log_file_wdata(file, fmt, args);
        _log_file_wlend(file);
        va_end(args);
        fclose(file); 
    }
}

ВСЁ. На нашей стороне аллокаций нет. Нет буферов, нет каких-то проверок.

UPD: Окей, я хлебнул черного бобового сока, распишу какие у вас косяки: 1.

   return (DEBUG_MSG   == type) ? "DEBUG"  
          :(INFO_MSG    == type) ? "INFO" 

Вот так делать не стоит совершенно. Поясняю, чем отличаются вот такие «колбасы» от switch. Если компилятор не «поймёт», что вы вообще делаете или если ваши перечисления идут не по порядку (не 0,1,2, а 10,20,31,18), то в таком случае он сгенерит отличную «колбасу» из cmp/jg/je, в которой будет проверять вообще всех членов множества по очереди. Если их там будет два десятка и логов будет сыпать много - то начнутся и кэш-миссы и общее замедление. На свищ компиль сразу понимает, что вы вообще творите и сразу строит или хэш-таблицу коллов, если они по порядку, то будет например вот так:

        push    rax
        cmp     edi, 5
        jae     .LBB1_2
        movsxd  rax, edi
        mov     rax, qword ptr [8*rax + .Lswitch.table._get_type_msg]
        pop     rcx
        ret

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

enum msg_type {
    LOG_DBG,
    LOG_INF = 30,
    LOG_WRN,
    LOG_ERR = 40,
    LOG_CRT
};

const char *_get_type_msg(enum msg_type type) {
    switch (type) {
        case LOG_DBG: return "DEBUG";
        case LOG_INF: return "INFO";
        case LOG_WRN: return "WARNING";
        case LOG_ERR: return "ERROR";
        case LOG_CRT: return "FATAL";
    }
}
_get_type_msg:
        mov     eax, offset .L.str
        add     edi, -30; << Смотреть сюда
        cmp     edi, 11 ; <<
        ja      .LBB0_6
        jmp     qword ptr [8*rdi + .LJTI0_0]
.LBB0_2:
        mov     eax, offset .L.str.1
        ret
.LBB0_3:
        mov     eax, offset .L.str.2
        ret
.LBB0_4:
        mov     eax, offset .L.str.3
        ret
.LBB0_5:
        mov     eax, offset .L.str.4
.LBB0_6:
        ret

Еще один плюс switch см. в п.2
То же самое замечание для ? stderr : stdout. Лучше напишите switch, чем потом забудете какой-то член и получите вывод не в тот поток.

  1. Зачем нужен abort(), а не exit. Я умышленно поставил abort, потому что а) при нормальном кодинге до него код никогда не дойдет. Если всё происходит в пределах одного модуля и у вас нет отправки мусора вместо enum - то abort() даже не будет после компиляции. Если всё происходит в разных юнитах транзакции, то тогда такой abort позволяет отловить место, где вы отправили именно что мусор, потому что по контракту вызова там должен быть enum. Разница между abort и exit в том, что abort создает core-файл, который позволяет найти конкретное место падения.

2.1 Про abort() после switch без default. Если вы добавите еще один член множества, то вы забудете добавить его во всех местах, где есть этот switch по множеству. В случае, если вы НЕ добавить default - компилятор вам скажет, что тут не обработан один из членов множества.

  1. Чем плох ваш мультистроковый вывод. Уровень сообщений добавляется по двум причинам:
  • Или вы хотите через например ENV контролировать уровень вывода (сравните вывод curl и curl -v / -vv)
  • Или в итоговом файле вы хотите отфильтровать записи:
grep "INFO" log.file
[INFO] ...
[INFO] ...

С мультилайном такой трюк не прокатит. Поэтому или откажитесь от мультилайна, или напишите отдельную функцию, которая через strtok будет искать \n и в цикле вызывать однолайновый log. Так мы сделали, например, для вывода логотипа при старте. На самом деле для ваших целей тут тоже никакие аллокации не нужны, если вы работаете с фиксированными типами:

// P.S. Я в упор не понимаю, почему вы не перенесете name в MAT4, но как хотите
void log_M4x4(enum log_level level, const char *name, const MAT4x4 *m) {
    log(level, "[MAT4x4] %s = [", name);
    log(level, "    [%9.3f, %9.3f, %9.3f, %9.3f],", m->M[0], m->M[4], m->M[ 8], m->M[12]);
    log(level, "    [%9.3f, %9.3f, %9.3f, %9.3f],", m->M[1], m->M[5], m->M[ 9], m->M[13]);
    log(level, "    [%9.3f, %9.3f, %9.3f, %9.3f],", m->M[2], m->M[6], m->M[10], m->M[14]);
    log(level, "    [%9.3f, %9.3f, %9.3f, %9.3f],", m->M[3], m->M[7], m->M[11], m->M[15]);
    log(level, "}");
}

P.P.S. У вас, кстати, жесточайший косяк с форматтером и выводом. В форматтере у вас 4 блока, в выводе 3. У вас куча байтов пишутся мимо кассы. Это потому, что вы вывели форматтер в отдельную переменную, компилятор не может проверить, что вы посылаете:

    const char fmt[]="%s = \n    [%9.3f, %9.3f, %9.3f, %9.3f]\n    |%9.3f, %9.3f, %9.3f, %9.3f|\n    |%9.3f, %9.3f, %9.3f, %9.3f|\n    [%9.3f, %9.3f, %9.3f, %9.3f]\n";
    int sz = snprintf(NULL, 0, fmt, name, m->M[0], m->M[4], m->M[ 8], m->M[12],
                                          m->M[1], m->M[5], m->M[ 9], m->M[13],
                                          m->M[2], m->M[6], m->M[10], m->M[14]);

Исходная версия PPP328, :

Что скажете?

Честно, мне лень смотреть.

Не совсем понял «вы можете вообще убрать это вызов» что вы имели в виду?

Окей, я имел в виду код вообще без аллокаций (на стороне кода).

Смотрите, разберем то, что вы хотите отправить:

[INFO]: [07/08/2024  13:35:26.286] Variable ENV_SUPERUSER is not set \n
^^^^^^
Тип сообщения
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
        Время/дата
                                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
                                   Сообщение с %s
                                                                     ^^
                                                                     Каретка

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

// Пишет в file тип сообщения и время
static void _log_file_wtime(FILE *file, enum log_level level) {
    struct timespec ts;
    clock_gettime(CLOCK_REALTIME, &ts); 
    struct tm *lt = localtime(&ts.tv_sec);

    fprintf(
        file,
        "[%s]: [%02d/%02d/%4d  %02d:%02d:%02d.%03d] ",
        _log_str_level(level),
        lt->tm_mday, 
        lt->tm_mon+1, 
        lt->tm_year+1900, 
        lt->tm_hour, 
        lt->tm_min, 
        lt->tm_sec, 
        (int)(1e-6*ts.tv_nsec)
    );
}

// Пишет в file переданные исходно данные
static void _log_file_wdata(FILE *file, const char *fmt, va_list args) {
    vfprintf(file, fmt, args);
}

// Пишет в file \n
static void _log_file_wlend(FILE *file) {
    fprintf(file, "\n");
}

И эти вызовы переезжают на замену вот этому: _log_file_write:

__attribute__((format(printf, 2, 3)) 
void log(enum log_level level, const char *fmt, ...) {

    va_list args;
    va_start(args, fmt);
    FILE *stdfile = _log_std_file(level);
    _log_file_whead(stdfile, level);
    _log_file_wdata(stdfile, fmt, args);
    _log_file_wlend(stdfile);
    va_end(args);


    static const char *log_env_file = "LOG_FILENAME";
    const char *filename = getenv(log_env_file);
    
    if (filename) {
        FILE *file = fopen(filename, "a");
        if (!file)
            // Ну вы тут сами обработку ошибок напишите, мне лень

        va_start(args, fmt);
        _log_file_whead(file, level);
        _log_file_wdata(file, fmt, args);
        _log_file_wlend(file);
        va_end(args);
        fclose(file); 
    }
}

ВСЁ. На нашей стороне аллокаций нет. Нет буферов, нет каких-то проверок.

UPD: Окей, я хлебнул черного бобового сока, распишу какие у вас косяки: 1.

   return (DEBUG_MSG   == type) ? "DEBUG"  
          :(INFO_MSG    == type) ? "INFO" 

Вот так делать не стоит совершенно. Поясняю, чем отличаются вот такие «колбасы» от switch. Если компилятор не «поймёт», что вы вообще делаете или если ваши перечисления идут не по порядку (не 0,1,2, а 10,20,31,18), то в таком случае он сгенерит отличную «колбасу» из cmp/jg/je, в которой будет проверять вообще всех членов множества по очереди. Если их там будет два десятка и логов будет сыпать много - то начнутся и кэш-миссы и общее замедление. На свищ компиль сразу понимает, что вы вообще творите и сразу строит или хэш-таблицу коллов, если они по порядку, то будет например вот так:

        push    rax
        cmp     edi, 5
        jae     .LBB1_2
        movsxd  rax, edi
        mov     rax, qword ptr [8*rax + .Lswitch.table._get_type_msg]
        pop     rcx
        ret

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

enum msg_type {
    LOG_DBG,
    LOG_INF = 30,
    LOG_WRN,
    LOG_ERR = 40,
    LOG_CRT
};

const char *_get_type_msg(enum msg_type type) {
    switch (type) {
        case LOG_DBG: return "DEBUG";
        case LOG_INF: return "INFO";
        case LOG_WRN: return "WARNING";
        case LOG_ERR: return "ERROR";
        case LOG_CRT: return "FATAL";
    }
}
_get_type_msg:
        mov     eax, offset .L.str
        add     edi, -30; << Смотреть сюда
        cmp     edi, 11 ; <<
        ja      .LBB0_6
        jmp     qword ptr [8*rdi + .LJTI0_0]
.LBB0_2:
        mov     eax, offset .L.str.1
        ret
.LBB0_3:
        mov     eax, offset .L.str.2
        ret
.LBB0_4:
        mov     eax, offset .L.str.3
        ret
.LBB0_5:
        mov     eax, offset .L.str.4
.LBB0_6:
        ret

Еще один плюс switch см. в п.2
То же самое замечание для ? stderr : stdout. Лучше напишите switch, чем потом забудете какой-то член и получите вывод не в тот поток.

  1. Зачем нужен abort(), а не exit. Я умышленно поставил abort, потому что а) при нормальном кодинге до него код никогда не дойдет. Если всё происходит в пределах одного модуля и у вас нет отправки мусора вместо enum - то abort() даже не будет после компиляции. Если всё происходит в разных юнитах транзакции, то тогда такой abort позволяет отловить место, где вы отправили именно что мусор, потому что по контракту вызова там должен быть enum. Разница между abort и exit в том, что abort создает core-файл, который позволяет найти конкретное место падения.

2.1 Про abort() после switch без default. Если вы добавите еще один член множества, то вы забудете добавить его во всех местах, где есть этот switch по множеству. В случае, если вы НЕ добавить default - компилятор вам скажет, что тут не обработан один из членов множества.

  1. Чем плох ваш мультистроковый вывод. Уровень сообщений добавляется по двум причинам:
  • Или вы хотите через например ENV контролировать уровень вывода (сравните вывод curl и curl -v / -vv)
  • Или в итоговом файле вы хотите отфильтровать записи:
grep "INFO" log.file
[INFO] ...
[INFO] ...

С мультилайном такой трюк не прокатит. Поэтому или откажитесь от мультилайна, или напишите отдельную функцию, которая через strtok будет искать \n и в цикле вызывать однолайновый log. Так мы сделали, например, для вывода логотипа при старте. На самом деле для ваших целей тут тоже никакие аллокации не нужны, если вы работаете с фиксированными типами:

// P.S. Я в упор не понимаю, почему вы не перенесете name в MAT4, но как хотите
void log_M4x4(enum log_level level, const char *name, const MAT4x4 *m) {
    log(level, "[MAT4x4] %s = [", name);
    log(level, "    [%9.3f, %9.3f, %9.3f, %9.3f],", m->M[0], m->M[4], m->M[ 8], m->M[12]);
    log(level, "    [%9.3f, %9.3f, %9.3f, %9.3f],", m->M[1], m->M[5], m->M[ 9], m->M[13]);
    log(level, "    [%9.3f, %9.3f, %9.3f, %9.3f],", m->M[2], m->M[6], m->M[10], m->M[14]);
    log(level, "    [%9.3f, %9.3f, %9.3f, %9.3f],", m->M[3], m->M[7], m->M[11], m->M[15]);
    log(level, "}");
}

P.P.S. У вас, кстати, жесточайший косяк с форматтером и выводом. В форматтере у вас 4 блока, в выводе 3. У вас куча байтов пишутся мимо кассы. Это потому, что вы вывели форматтер в отдельную переменную, компилятор не может проверить, что вы посылаете:

    const char fmt[]="%s = \n    [%9.3f, %9.3f, %9.3f, %9.3f]\n    |%9.3f, %9.3f, %9.3f, %9.3f|\n    |%9.3f, %9.3f, %9.3f, %9.3f|\n    [%9.3f, %9.3f, %9.3f, %9.3f]\n";
    int sz = snprintf(NULL, 0, fmt, name, m->M[0], m->M[4], m->M[ 8], m->M[12],
                                          m->M[1], m->M[5], m->M[ 9], m->M[13],
                                          m->M[2], m->M[6], m->M[10], m->M[14]);