c++ - Evitar fugas en el uso trivial de Boost Log

logging memory-leaks

Question

Estoy recibiendo informes de fugas de valgrind desde una aplicación del lado del servidor que usa boostlog que se distribuye con boost 1.56. el informe valgrind es:

== 8021 == 37,088 bytes en 1,159 bloques definitivamente se pierden en el registro de pérdidas 1,613 de 1,642

== 8021 == a 0x4A05588: memalign (vg_replace_malloc.c: 727)

== 8021 == por 0x3FDA61118F: tls_get_addr_tail (en /lib64/ld-2.12.so)

== 8021 == por 0x3FDA61165F: __tls_get_addr (en /lib64/ld-2.12.so)

== 8021 == por 0x3FE6ABBDCB: __cxa_get_globals (en /usr/lib64/libstdc++.so.6.0.13)

== 8021 == por 0x730C528: boost :: log :: v2_mt_posix :: aux :: unhandled_exception_count () (en /opt/sesteksdk/lib/libboost_log.so.1.56.0)

== 8021 == por 0x5D54D1F: sestek :: mrcp :: audio :: reconocimiento :: AsynchronousRecognizer :: Notify (sestek :: voz :: reconocimiento :: IRecognizerNotification const *) (record_ostream.hpp: 259)

esta fuga proviene de una línea tan simple como:
LOGGER(debug)<< _chanProp->GetId() << " got recognition ended notification from recognizer";

Recibimos 5 de estas filtraciones solo a partir de una única prueba de corta duración.

usamos backend de archivos de texto, con sink syncronous, el auto flush está activado. Básicamente:

void InitializeFileLog(const std::string & logDir)
    {   
        boost::shared_ptr< logging::core > loggingCore = logging::core::get();


        loggingCore->add_global_attribute("TimeStamp", attrs::local_clock());

        string logPath = logDir + "/gvzmrcpsr_%N.txt";

        boost::shared_ptr< sinks::text_file_backend > backend =
            boost::make_shared< sinks::text_file_backend >(
                // file name pattern
                keywords::file_name = logPath,
                // rotate the file upon reaching 5 MiB size...
                keywords::rotation_size = 5 * 1024 * 1024,
                // ...or at midnight, whichever comes first
                keywords::time_based_rotation = sinks::file::rotation_at_time_point(0, 0, 0)                    
            );

        backend->auto_flush(true);

        // Wrap it into the frontend and register in the core.
        // The backend requires synchronization in the frontend.
        typedef sinks::synchronous_sink< sinks::text_file_backend > sink_t;
        boost::shared_ptr< sink_t > sink = boost::make_shared< sink_t>(backend);

        loggingCore->add_sink(sink);


        sink->flush();
        sink->set_formatter
            (
            expr::stream
            << expr::attr< boost::posix_time::ptime >("TimeStamp")
            << " : [" << expr::attr< sestek::log::LogLevel >("Severity")
            << "] " << expr::smessage
            );

        backend->set_file_collector(sinks::file::make_collector(
            // rotated logs will be moved here
            keywords::target = logDir + "/old_mrcpsr_plugin_logs",
            // oldest log files will be removed if the total size reaches 100 MiB...
            keywords::max_size = 100 * 1024 * 1024,
            // ...or the free space in the target directory comes down to 50 MiB
            keywords::min_free_space = 50 * 1024 * 1024
        ));

        try
        {
            backend->scan_for_files(sinks::file::scan_all);
        }
        catch(std::exception & )
        {
            //LOGGER(sestek::log::fatal) << "exception during scanning : " << e.what();

        }

    }

El sistema se compila y ejecuta en centos 6.6 usando devtoolkit2.0. la versión de gcc es 4.8.2.

Entonces, ¿hay algún problema en nuestro uso del registro de refuerzo? ¿O el registro de impulso realmente tiene ese (s) problema (s)? Creo que nuestro uso puede considerarse trivial, solo ejecutamos el código de configuración anterior durante la puesta en marcha.

Nota: Aunque un solo tamaño de fuga puede ser lo suficientemente pequeño, nuestro software se ejecuta como un servicio en un servidor, por lo que este tipo de fuga repetitiva es problemático para nosotros.

Answer 1

Boost Log - como muchas otras bibliotecas de registro - usa tls internamente. Es difícil (y a veces parece imposible) que un sistema de registro limpie las variables tls cuando termina un hilo. Boost enfrenta las mismas dificultades.

Para una aplicación de larga ejecución que contiene código de registro, separar muchos hilos y terminarlos cuando se realiza su tarea no es un buen uso. Un mejor enfoque en un sistema con muchas tareas múltiples es usar un grupo de subprocesos en lugar de iniciar nuevos subprocesos todas y cada una de las veces.

Convertí la aplicación para usar un grupo de subprocesos y las filtraciones en la pregunta han desaparecido. Las variables Tls siguen ahí, pero como ahora los hilos se reutilizan, las variables también se reutilizan mediante los hilos correspondientes.

Answer 2

El objeto filtrado es una parte interna del tiempo de ejecución C ++, que no está creado explícitamente por Boost.Log. Según lo que puedo ver, este objeto se crea por subproceso y, como tal, debe destruirse cuando termina el subproceso. Tu uso de Boost.Log me parece bien.

Answer 3

Realmente no entiendo la pregunta. Muestra evidencia de una fuga y pregunta "¿se filtra"? Bueno, sí. Esto no es sorprendente. Los registradores usan subprocesos locales "singletons". Dependiendo de cómo organizó sus hilos, será posible / casi imposible romperlos adecuadamente.

Es hora de hacer un SSCCE y acceder a la documentación sobre las secuencias de apagado correctas.

Nota

El cierre de los registradores es notoriamente difícil. Debe tratar con la posibilidad de que algo tenga que registrarse durante el apagado (un olor de diseño); Peor aún, diferentes sumideros podrían depender el uno del otro y evitar el apagado en cualquier orden particular).

Bastantes frameworks simplemente dejan al sistema operativo la limpieza.

PS Nada indica una fuga repetitiva, ya que parece una fuga por hilo.