Пробы, трассировка, логирование в Си

Пробы, трассировка, логирование в Си

Сегодня придумал и реализовал следующий подход для логирования. Хочется
вызывать некий log(key0, val0, key1, val1, ...), чтобы выводились хоть в
каком-либо формате key-value значения. Когда есть какое-нибудь шифрование,
MAC или подобное, то выводить же хочется массу параметров: iv/nonce, ad,
ключи, диверсифицированные ключи и подобное.

Писать длиннющие printf -- вариант, но громоздкий. Особенно учитывая то,
что ведь бинарные данные нужно в hex (а то и "hexdump -C"-like выводе)
делать. Оборачивать val* значения в struct какой-нибудь, где был бы
признак типа данных для va_args, чтобы понимать как надо распечатывать --
громоздко.

У DJB в коде есть много log1, log2, log3, которые принимают один char*,
или два char*, или три. Мне же так просто не отделываться.

Вспомнил про то, что я не раз ведь обмазывал код USDT пробами,
использовал DTrace. Ведь там я заранее говорю какие пробы будут, какие
аргументы они принимают. В боевом коде все эти пробы занимают типа по
одной строке, не делая никаких преобразований с данными до вызова. diff
маленький, в глаз не бросается огромная куча кода.

Так почему бы не генерировать конкретно для каждой пробы по функции,
которая бы знала как именно распечатывать каждый аргумент? Чуть более
экрана кода на Tcl, и я могу описать пробы в таком виде:

    set streebog512 64

    probe SysErr {err errno}
    probe HMACInit {is512 bool} {key bin}
    probe HMACWrite {ref} {data bin}
    probe HMACSum {ref} {sum bin}
    probe HKDF {key bin} {info bin}
    probe HKDFOut0 {ref} "out bin $streebog512"
    probe HKDFOut1 {ref} "out bin $streebog512"
    probe HKDFOut2 {ref} "out bin $streebog512"

и будет сгенерирован такой код:

    ProbeId
    ProbeHMACWrite(
        const ProbeId ref,
        const unsigned char *data,
        const size_t dataLen
    )
    {
        Probes.id++;
        if (!Probes.enabled.HMACWrite) {
            return Probes.id;
        }
        probePrefix("HMACWrite");
        {
            Assert(snprintf((char *)Probes.buf, sizeof Probes.buf, "ref=%08zu ", ref) > 0);
            fputs((const char *)Probes.buf, Probes.fh);
        }
        {
            fputs("data=", Probes.fh);
            HexEnc(Probes.buf, data, dataLen);
            Probes.buf[dataLen * 2] = 0;
            fputs((const char *)Probes.buf, Probes.fh);
        }
        fputs("\n", Probes.fh);
        fflush(Probes.fh);
        return Probes.id;
    }

где в боевом коде достаточно будет вставить:

    [...]
    ProbeId parentProbeId = ProbeHMACInit(is512, key, keyLen);
    [...]
    ProbeHMACWrite(parentProbeId, data, dataLen);

а заголовочный файл тоже автоматически генерируется:

    [...]
    ProbeId
    ProbeHKDFOut0(
        const ProbeId ref,
        const unsigned char out[64]);
    [...]
    struct ProbesEnabled {
        bool HMACInit;
        bool HMACWrite;
        bool HMACSum;
        bool HKDF;
        bool HKDFOut0;
        bool HKDFOut1;
        bool HKDFOut2;
        unsigned char pad[1];
    };

И я могу включать/выключать пробы просто через Probes.enabled.XXX, и где
известной длины поля бинарные, то не указывать их. errno тип будет
распечатан и в человекочитаемом виде. Каждая проба имеет порядковый
номер, на который можно сослаться через {ref} аргумент. Код обмазывается
проще чем DTrace. Новые типы данных (соответственно, и как их распечатывать)
вводить легко.