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

Напишите где-нибудь в UI потоке (например в методе onStart) такой код:

//где-то в UI потокеrunBlocking(Dispatchers.Main) {  println(Hello, World!)}

Вы получите дедлок приложение зависнет. Это не ошибка, а на 100% ожидаемое поведение. Тезис может показаться неочевидным и неявным, поэтому давайте погрузимся поглубже и я расскажу, что здесь происходит.

Сравним код выше с более низкоуровневым подходом с потоками. Вы можете написать в главном потоке вот так:

//где-то в UI потокеHandler().post {println("Hello, World!") // отработает в UI потоке}

Или даже так:

//где-то в UI потокеrunOnUiThread {  println("Hello, World!") // и это тоже отработает в UI потоке}

Вроде конструкция очень похожа на наш проблемный код, но здесь обе части кода работают (по-разному под капотом, но работают). Чем они отличаются от кода с runBlocking?

Как работает runBlocking

Для начала небольшой дисклеймер. runBlocking редко используется в продакшн коде Android-приложения. Обычно он предназначен для использования в синхронном коде, вроде функций main или unit-тестах.

Несмотря на это, мы всё-таки рассмотрим этот билдер при вызове в главном потоке Android-приложения потому, что:

• Это наглядно. Ниже мы придем к тому, что это актуально и не только для UI-потока Android-приложения. Но для наглядности лучше всего подходит пример на UI-потоке.

• Интересно разобраться, почему всё именно так работает.

• Всё-таки иногда мы можем использовать runBlocking, пусть даже в тестовых приложениях.

Билдер runBlocking работает почти так же, как и launch: создает корутину и вызывает в ней блок кода. Но чтобы сделать вызов блокирующим runBlocking создает особую корутину под названием BlockingCoroutine, у которой есть дополнительная функция joinBlocking(). runBlocking вызывает joinBlocking() сразу же после запуска корутины.

Фрагмент из runBlocking():

// runBlocking() function// val coroutine = BlockingCoroutine<T>(newContext, )coroutine.start(CoroutineStart.DEFAULT, coroutine, block)return coroutine.joinBlocking()

Функция joinBlocking() использует механизм блокировки Java LockSupport для блокировки текущего потока с помощью функции park(). LockSupport это низкоуровневый и высокопроизводительный инструмент, обычно используется для написания собственных блокировок.

Кроме того, BlockingCoroutine переопределяет функцию afterCompletion(), которая вызывается после завершения работы корутины.

override fun afterCompletion(state: Any?) {//wake up blocked threadif (Thread.currentThread ()! = blockedThread)LockSupport.unpark (blockedThread)}

Эта функция просто разблокирует поток, если она была заблокирована до этого с помощью park().

Как это всё работает примерно показано на схеме работы runBlocking.

Что здесь делает Dispatchers

Хорошо, мы поняли, что делает билдер runBlocking. Но почему в одном случае он блокирует UI-поток, а в другом нет? Почему Dispatchers.Main приводит к дедлоку...

// Этот код создает дедлокrunBlocking(Dispatchers.Main) {  println(Hello, World!)}

...,а Dispatchers.Default нет?

// А этот код создает дедлокrunBlocking(Dispatchers.Default) {  println(Hello, World!)}

Для этого вспомним, что такое диспатчер и зачем он нужен.

Диспатчер определяет, какой поток или потоки использует корутина для своего выполнения. Это некий высокоуровневый аналог Java Executor. Мы даже можем создать диспатчер из Executorа с помощью удобного экстеншна:

public fun Executor.asCoroutineDispatcher(): CoroutineDispatcher

Dispatchers.Default реализует класс DefaultScheduler и делегирует обработку исполняемого блока кода объекту coroutineScheduler. Его функция dispatch() выглядит так:

override fun dispatch (context: CoroutineContext, block: Runnable) =  try {    coroutineScheduler.dispatch (block)  } catch (e: RejectedExecutionException) {    //    DefaultExecutor.dispatch(context, block)  }

Класс CoroutineScheduler отвечает за наиболее эффективное распределение обработанных корутин по потокам. Он реализует интерфейс Executor.

override fun execute(command: Runnable) = dispatch(command)

А что же делает функция CoroutineScheduler.dispatch()?

• Добавляет исполняемый блок в очередь задач. При этом существует две очереди: локальная и глобальная. Это часть механизма приоритезации внешних задач.

• Создает воркеры. Воркер это класс, унаследованный от обычного Java Thread (в данном случае daemon thread). Здесь создаются рабочие потоки. У воркера также есть локальная и глобальная очереди, из которых он выбирает задачи и выполняет их.

• Запускает воркеры.

Теперь соединим всё, что разобрали выше про Dispatchers.Default, и напишем, что происходит в целом.

• runBlocking запускает корутину, которая вызывает CoroutineScheduler.dispatch().

• dispatch() запускает воркеры (под капотом Java потоки).

• BlockingCoroutine блокирует текущий поток с помощью функции LockSupport.park().

• Исполняемый блок кода выполняется.

• Вызывается функция afterCompletion(), которая разблокирует текущий поток с помощью LockSupport.unpark().

Эта последовательность действий выглядит примерно так.

Перейдём к Dispatchers.Main

Это диспатчер, который создан специально для Android. Например, при использовании Dispatchers.Main фреймворк бросит исключение, если вы не добавляете зависимость:

implementation 'org.jetbrains.kotlinx:kotlinx-coroutines-android:..*'

Перед началом разбора Dispatchers.Main стоит поговорить о HandlerContext. Это специальный класс, который добавлен в пакет coroutines для Android. Это диспатчер, который выполняет задачи с помощью Android Handler всё просто.

Dispatchers.Main создаёт HandlerContext с помощью AndroidDispatcherFactory через функцию createDispatcher().

override fun createDispatcher() =  HandlerContext(Looper.getMainLooper().asHandler(async = true))

И что мы тут видим? Looper.getMainLooper().asHandler() означает, что он принимает Handler главного потока Android. Получается, что Dispatchers.Main это просто HandlerContext с Handlerом главного потока Android.

Теперь посмотрим на функцию dispatch() у HandlerContext:

override fun dispatch(context: CoroutineContext, block: Runnable) {  handler.post(block)}

Он просто постит исполняемый код через Handler. В нашем случае Handler главного потока.

Итого, что же происходит?

• runBlocking запускает корутину, которая вызывает CoroutineScheduler.dispatch().

• dispatch() отправляет исполняемый блок кода через Handler главного потока.

• BlockingCoroutine блокирует текущий поток с помощью функции LockSupport.park().

• Main Looper никогда не получает сообщение с исполняемым блоком кода, потому что главный поток заблокирован.

• Из-за этого afterCompletion() никогда не вызывается.

• И из-за этого текущий поток не будет разблокирован (через unparked) в функции afterCompletion().

Эта последовательность действий выглядит примерно так.

Вот почему runBlocking с Dispatchers.Main блокирует UI-поток навсегда.

Главный потокблокируется и ждёт завершения исполняемого кода. Но он никогда не завершается, потому что Main Looper не может получить сообщение на запуск исполняемого кода. Дедлок.

Совсем простое объяснение

Помните пример с Handler().post в самом начале статьи? Там код работает и ничего не блокируется. Однако мы можем легко изменить его, чтобы он был в значительной степени похож на наш код с Dispatcher.Main, и стал ещё нагляднее. Для этого можем добавить операции parking и unparking к текущему потоку, иммитируя работу функций afterCompletion() и joinBlocking(). Код начинает работать почти так же, как с билдером runBlocking.

//где-то в UI потокеval thread = Thread.currentThread()Handler().post {  println("Hello, World!") // это никогда не будет вызвано  // имитируем afterCompletion()  LockSupport.unpark(thread)}// имитируем joinBlocking()LockSupport.park()

Но этот трюк не будет работать с функцией runOnUiThread.

//где-то в UI потокеval thread = Thread.currentThread()runOnUiThread {  println("Hello, World!") // этот код вызовется  LockSupport.unpark(thread)}LockSupport.park()

Это происходит потому, что runOnUiThread использует оптимизацию, проверяя текущий поток. Если текущий поток главный, то он сразу же выполнит блок кода. В противном случае сделает post в Handler главного потока.

Если всё же очень хочется использовать runBlocking в UI-потоке, то у Dispatchers.Main есть оптимизация Dispatchers.Main.immediate. Там аналогичная логика как у runOnUiThread. Поэтому этот блок кода будет работать и в UI-потоке:

//где-то в UI потокеrunBlocking(Dispatchers.Main.immediate) {   println(Hello, World!)}

Выводы

В статье я описал как безобидный билдер runBlocking может заморозить ваше приложение на Android. Это произойдет, если вызвать runBlocking в UI-потоке с диспатчером Dispatchers.Main. Приложение заблокируется по следующему алгоритму:

• runBlocking создаёт блокирующую корутину BlockingCoroutine.

• Dispatchers.Main отправляет на запуск исполняемый блок кода через Handler.post.

• Но BlockingCoroutine тут же заблокирует UI поток.

• Поэтому Main Looper никогда не получит сообщение с исполняемым блоком кода.

• А UI не разблокируется, потому что корутина ждёт завершения исполняемого кода.

Эта статья больше теоретическая, чем практическая. Просто потому, что runBlocking редко встречается в продакшн-коде. Но примеры с UI-потоком наглядны, потому что можно сразу заблокировать приложение и разобраться, как работает runBlocking.

Но заблокировать исполнение можно не только в UI-потоке, но и с помощью других диспатчеров, если поток вызова и корутины окажется одним и тем же. В такую ситуацию можно попасть, если мы будем пытаться вызвать билдер runBlocking на том же самом потоке, что и корутина внутри него. Например, мы можем использовать newSingleThreadContext для создания нового диспатчера и результат будет тот же. Здесь UI не будет заморожен, но выполнение будет заблокировано.

val singleThreadDispatcher = newSingleThreadContext("Single Thread")GlobalScope.launch (singleThreadDispatcher) {  runBlocking (singleThreadDispatcher) {    println("Hello, World!") // этот кусок кода опять не выполнится  }}

Если очень надо написать runBlocking в главном потоке Android-приложения, то не используйте Dispatchers.Main. Используйте Dispatchers.Default или Dispatchers.Main.immediate в крайнем случае.

Также будет интересно почитать:

Оригинал статьи на английском How runBlocking May Surprise You.
Как страдали iOS-ники когда выпиливали Realm.
О том, над чем в целом мы тут работаем: монолит, монолит, опять монолит.
Кратко об истории Open Source просто развлечься (да и статья хорошая).

Подписывайтесь начат Dodo Engineering, если хотите обсудить эту и другие наши статьи и подходы, а также на канал Dodo Engineering, где мы постим всё, что с нами интересного происходит.

Для написания эффективных и корректных многопоточных приложений очень важно знать какие существуют механизмы синхронизации памяти между потоками исполнения, какие гарантии предоставляют элементы многопоточного программирования, такие как мьютекс, join потока и другие. Особенно это касается модели памяти C++, которая была создана сложной таковой, чтобы обеспечивать оптимальный многопоточный код под множество архитектур процессоров. Кстати, язык программирования Rust, будучи построенным на LLVM, использует модель памяти такую же, как в C++. Поэтому материал в этой статье будет полезен программистам на обоих языках. Но все примеры будут на языке C++. Я буду рассказывать про std::atomic, std::memory_order и на каких трех слонах стоят атомики.

В стандарте C++11 появилась возможность писать многопоточные программы на C++, используя только стандартные средства языка. В то время многоядерные процессоры уже завоевали рынок. Особенность выполнения программы на многоядерном процессоре в том, что инструкции программы из разных потоков физически могут исполняться одновременно. Ранее многопоточность на одном ядре эмулировалась частым переключением контекста исполнения с одного потока на последующие. Для оптимизации работы с памятью у каждого ядра имеется его личный кэш памяти, над ним стоит общий кэш памяти процессора, далее оперативная память. Задача синхронизации памяти между ядрами - поддержка консистентного представления данных на каждом ядре (читай в каждом потоке). Очевидно, что если применить строгую упорядоченность изменений памяти, то операции на разных ядрах уже не будут выполнятся параллельно: остальные ядра будут ожидать, когда одно ядро выполнит инструкции изменения данных. Поэтому процессоры поддерживают работу с памятью с менее строгими гарантиями консистентности памяти. Более того, разработчику программы предоставляется выбор, какие гарантии по доступу к памяти из разных потоков требуются для достижения максимальной корректности и производительности многопоточной программы. Задача предоставить разные гарантии по памяти решалась по-разному для разных архитектур процессоров. Наиболее популярные архитектуры x86-64 и ARM имеют разные представления о том, как синхронизировать память.

Язык C++ компилируется под множество архитектур, поэтому в вопросе синхронизации данных между потоками в С++11 была добавлена модель памяти, которая обобщает механизмы синхронизации различных архитектур, позволяя генерировать для каждого процессора оптимальных код с необходимой степенью синхронизации.

Отсюда следует несколько важных выводов: модель синхронизации памяти C++ это "искусственные" правила, которые учитывают особенности различных архитектур процессоров. В модели C++ некоторые конструкции, описанные стандартом как undefined behavior (UB), могут корректно работать на одной архитектуре, но приводить к ошибкам работы с памятью на других архитектурах.

Наша задача, как разработчиков на языке C++, состоит в том, чтобы писать корректный с точки зрения стандарта языка код. В этом случае мы можем быть уверены, что для каждой платформы будет сгенерирован корректный машинный код.

Код каждого потока компилируется и выполняется так, как будто он один в программе. Вся синхронизация данных между потоками возложена на плечи атомиков (std::atomic), т.к. именно они предоставляют возможность форсировать "передачу" изменений данных в другой поток. Далее я покажу, что мьютексы (std::mutex) и другие многопоточные примитивы либо реализованы на атомиках, либо предоставляют гарантии, семантически похожие на атомарные операции. Поэтому ключом к написанию корректных многопоточных программ является понимание того, как конкретно работают атомики.

Три слона

На мой взгляд, основная проблема с атомиками в C++ состоит в том, что они несут сразу три функции. Так на каких же трех слонах держатся атомики?

1. Атомики позволяют реализовать атомарные операции.

2. Атомики накладывают ограничения на порядок выполнения операций с памятью в одном потоке.

3. Синхронизируют память в двух и более потоках выполнения.

Атомарная операция это операция, которую невозможно наблюдать в промежуточном состоянии, она либо выполнена либо нет. Атомарные операции могут состоять из нескольких операций. Если говорить про тип std::atomic, то он предоставляет ряд примитивных операций: load, store, fetch_add, compare_exchange_* и другие. Последние две операции это read-modify-write операции, атомарность которых обеспечивается специальными инструкциями процессора.

Рассмотрим простой пример read-modify-write операции, а именно прибавление к числу единицы. Пример 0, link:

static int v1 = 0;static std::atomic<int> v2{ 0 };void add_v1() {v1++;   /* Generated asm for x86-64:  mov eax, DWORD PTR v1[rip]  add eax, 1  mov DWORD PTR v1[rip], eax  */} void add_v2() {v2.fetch_add(1);   /* Generated asm for x86-64 (simplified):  mov edx, OFFSET FLAT:_ZL2v2  lock xadd DWORD PTR [rdx], 1  */}

В случае с обычной переменной v1 типа int имеем три отдельных операций: read-modify-write. Нет гарантий, что другое ядро процессора не выполняет другой операции над v1. Операция над v2 в машинных кодах представлена как одна операция с lock сигналом на уровне процессора, гарантирующим, что к кэш линии, в которой лежит v2, эксклюзивно имеет доступ только ядро, выполняющее эту инструкцию.

Про ограничения на порядок выполнения операций. Когда мы пишем код программы, то предполагаем, что операторы языка будут выполнены последовательно. В реальности же компилятор и в особенности процессор могут переупорядочить команды программы с целью оптимизации. Они это делают с учетом ограничений на порядок записи и чтения в локацию памяти. Например, чтение из локации памяти должно происходить после записи, эти операции нельзя переупорядочить. Применение атомарных операция может накладывать дополнительные ограничения на возможные переупорядочивания операций с памятью.

Про синхронизацию данных между потоками. Если мы хотим изменить данные в одном потоке и сделать так, чтобы эти изменения были видны в другом потоке, то нам необходимы примитивы многопоточного программирования. Фундаментальным таким примитивом являются атомики, остальные, например мьютексы, либо реализованы на основе атомиков, либо повторяют семантику атомиков. Все остальные попытки записывать и читать одни и те же данные из разных потоков могут приводить к UB.

Случаи, когда синхронизация памяти не требуется:

1. Если все потоки, работающие с одним участком памяти, используют ее только на чтение

2. Если разные потоки используют эксклюзивно разные участки памяти

Далее будет рассмотрены более сложные случаи, когда требуется чтение и запись одного участка памяти из разных потоков. Язык C++ предоставляет три способа синхронизации памяти. По мере возрастания строгости: relaxed, release/acquire и sequential consistency. Рассмотрим их.

Неделимый, но расслабленный

Самый простой для понимания флаг синхронизации памяти relaxed. Он гарантирует только свойство атомарности операций, при этом не может участвовать в процессе синхронизации данных между потоками. Свойства:

• модификация переменной "появится" в другом потоке не сразу

• поток thread2 "увидит" значения одной и той же переменной в том же порядке, в котором происходили её модификации в потоке thread1

• порядок модификаций разных переменных в потоке thread1 не сохранится в потоке thread2

Можно использовать relaxed модификатор в качестве счетчика. Пример 1, link:

std::atomic<size_t> counter{ 0 }; // process can be called from different threadsvoid process(Request req) {counter.fetch_add(1, std::memory_order_relaxed);// ...}void print_metrics() {std::cout << "Number of requests = " << counter.load() << "\n";// ...}

Использование в качестве флага остановки. Пример 2, link:

std::atomic<bool> stopped{ false }; void thread1() {while (!stopped.load(std::memory_order_relaxed)) {// ...}} void stop_thread1() {stopped.store(true, std::memory_order_relaxed);}

В данном примере не важен порядок в котором thread1 увидит изменения из потока, вызывающего stop_thread1. Также не важно то, чтобы thread1 мгновенно (синхронно) увидел выставление флага stopped в true.

Пример неверного использования relaxed в качестве флага готовности данных. Пример 3, link:

std::string data;std::atomic<bool> ready{ false }; void thread1() {data = "very important bytes";ready.store(true, std::memory_order_relaxed);} void thread2() {while (!ready.load(std::memory_order_relaxed));std::cout << "data is ready: " << data << "\n"; // potentially memory corruption is here}

Тут нет гарантий, что поток thread2 увидит изменения data ранее, чем изменение флага ready, т.к. синхронизацию памяти флаг relaxed не обеспечивает.

Полный порядок

Флаг синхронизации памяти "единая последовательность" (sequential consistency, seq_cst) самый строгий и понятный. Его свойства:

• порядок модификаций разных атомарных переменных в потоке thread1 сохранится в потоке thread2

• все потоки будут видеть один и тот же порядок модификации всех атомарных переменных. Сами модификации могут происходить в разных потоках

• все модификации памяти (не только модификации над атомиками) в потоке thread1, выполняющей store на атомарной переменной, будут видны после выполнения load этой же переменной в потоке thread2

Таким образом можно представить seq_cst операции, как барьеры памяти, в которых состояние памяти синхронизируется между всеми потоками программы. Другими словами, как будто многопоточная программа выполняется на одноядерном процессоре.

Этот флаг синхронизации памяти в C++ используется по-умолчанию, т.к. с ним меньше всего проблем с точки зрения корректности выполнения программы. Но seq_cst является дорогой операцией для процессоров, в которых вычислительные ядра слабо связаны между собой в плане механизмов обеспечения консистентности памяти. Например, для x86-64 seq_cst дешевле, чем для ARM архитектур.

Продемонстрируем второе свойство. Пример 4, из книги [1], link:

std::atomic<bool> x, y;std::atomic<int> z; void thread_write_x() {x.store(true, std::memory_order_seq_cst);} void thread_write_y() {y.store(true, std::memory_order_seq_cst);} void thread_read_x_then_y() {while (!x.load(std::memory_order_seq_cst));if (y.load(std::memory_order_seq_cst)) {++z;}}  void thread_read_y_then_x() {while (!y.load(std::memory_order_seq_cst));if (x.load(std::memory_order_seq_cst)) {++z;}}

После того, как все четыре потока отработают, значение переменной z будет равно 1 или 2, потому что потоки thread_read_x_then_y и thread_read_y_then_x "увидят" изменения x и y в одном и том же порядке. От запуска к запуску это могут быть: сначала x = true, потом y = true, или сначала y = true, потом x = true.

Модификатор seq_cst всегда может быть использован вместо relaxed и acquire/release, еще и поэтому он является модификатором по-умолчанию. Удобно использовать seq_cst для отладки проблем, связанных с гонкой данных в многопоточной программе: добиваемся корректной работы программы и далее заменяем seq_cst на менее строгие флаги синхронизации памяти. Примеры 1 и 2 также будут корректно работать, если заменить relaxed на seq_cst, а пример 3 начнет работать корректно после такой замены.

Синхронизация пары. Acquire/Release

Флаг синхронизации памяти acquire/release является более тонким способом синхронизировать данные между парой потоков. Два ключевых слова: memory_order_acquire и memory_order_release работают только в паре над одним атомарным объектом. Рассмотрим их свойства:

• модификация атомарной переменной с release будет мгновенно видна в другом потоке, выполняющим чтение этой же атомарной переменной с acquire

• все модификации памяти в потоке thread1, выполняющей запись атомарной переменной с release, будут видны после выполнения чтения той же переменной с acquire в потоке thread2

• процессор и компилятор не могут перенести операции записи в память ниже release операции в потоке thread1, и нельзя перемещать выше операции чтения из памяти выше acquire операции в потоке thread2

Важно понимать, что нет полного порядка между операциями над разными атомиками, происходящих в разных потоках. Например, в примере 4 если все операции store заменить на memory_order_release, а операции load заменить на memory_order_acquire, то значение z после выполнения программы может быть равно 0, 1 или 2. Это связано с тем, что, независимо от того в каком порядке по времени выполнения выполнены store для x и y, потоки thread_read_x_then_y и thread_read_y_then_x могут увидеть эти изменения в разных порядках. Кстати, такими же изменениями для load и store можно исправить пример 3. Такое изменение будет корректным и производительными, т.к. тут нам не требуется единый порядок изменений между всеми потоками (как в случае с seq_cst ), а требуется синхронизировать память между двумя потоками.

Используя release, мы даем инструкцию, что данные в этом потоке готовы для чтения из другого потока. Используя acquire, мы даем инструкцию "подгрузить" все данные, которые подготовил для нас первый поток. Но если мы делаем release и acquire на разных атомарных переменных, то получим UB вместо синхронизации памяти.

Рассмотрим реализацию простейшего мьютекса, который ожидает в цикле сброса флага, для того, чтобы получить lock. Такой мьютекс называют spinlock. Это не самый эффективный способ реализации мьютекса, но он обладает всеми нужными свойствами, на которые я хочу обратить внимание. Пример 5, link:

class mutex {public:void lock() {bool expected = false;while(!_locked.compare_exchange_weak(expected, true, std::memory_order_acquire)) {expected = false;}} void unlock() {_locked.store(false, std::memory_order_release);} private:std::atomic<bool> _locked;};

Функция lock() непрерывно пробует сменить значение с false на true с модификатором синхронизации памяти acquire. Разница между compare_exchage_weak и strong незначительна, про нее можно почитать на cppreference. Функция unlock() выставляет значение в false с синхронизацией release. Обратите внимание, что мьютекс не только обеспечивает эксклюзивным доступ к блоку кода, который он защищает. Он так же делает доступным те изменения памяти, которые были сделаны до вызова unlock() в коде, который будет работать после вызова lock(). Это важное свойство. Иногда может сложиться ошибочное мнение, что мьютекс в конкретном месте не нужен.

Рассмотрим такой пример, называемый Double Checked Locking Anti-Pattern из [2]. Пример 6, link:

struct Singleton {// ...}; static Singleton* singleton = nullptr;static std::mutex mtx;static bool initialized = false; void lazy_init() {if (initialized) // early return to avoid touching mutex every callreturn; std::unique_lock l(mtx); // `mutex` locks here (acquire memory)if (!initialized) {singleton = new Singleton();initialized = true;}// `mutex` unlocks here (release memory)}

Идея проста: хотим единожды в рантайме инициализировать объект Singleton. Это нужно сделать потокобезопасно, поэтому имеем мьютекс и флаг инициализации. Т.к. создается объект единожды, а используется singleton указатель в read-only режиме всю оставшуюся жизнь программы, то кажется разумным добавить предварительную проверку if (initialized) return. Данный код будет корректно работать на архитектурах процессора с более строгими гарантиями консистентности памяти, например в x86-64. Но данный код неверный с точки зрения стандарта C++. Давайте рассмотрим такой сценарий использования:

void thread1() {lazy_init();singleton->do_job();} void thread2() {lazy_init();singleton->do_job();}

Рассмотрим следующую последовательность действий во времени:

1. сначала отрабатывает thread1 -> выполняет инициализацию под мьютексом:

• lock мьютекса (acquire)

• singleton = ..

• initialized = true

• unlock мьютекса (release)

2. далее в игру вступает thread2:

• if(initalized) возвращает true (память, где содержится initialized могла быть неявно синхронизирована между ядрами процессора)

• singleton->do_job() приводит к segmentation fault (указатель singleton не обязан был быть синхронизирован с потоком thread1)

Этот случай интересен тем, что наглядно показывает роль мьютекса не только как примитива синхронизации потока выполнения, но и синхронизации памяти.

Семантика acquire/release классов стандартной библиотеки

Механизм acquire/release поможет понять гарантии синхронизации памяти, которые предоставляют классы стандартной библиотеки для работы с потоками. Ниже приведу список наиболее часто используемых операций.

И так далее. Полный список можно найти в книге [1].

Что это все значит? Повторю эту важную мысль еще раз: это значит, на примере std::promise::set_value и std::future::wait, что тут мы не только получили данные, которые содержатся в примитиве синхронизации, но и нам доступны все изменения памяти, которые были в потоке до того, как он выполнил set_value. Это маленькое чудо нам кажется само собой разумеющееся с нашим бытовым, последовательным причинно-следственным, взглядом на мир. Но в мире многоядерного процессора, законы которого больше похожи на квантовую физику, которую никто до конца не понимает, нет единого последовательно порядка изменения памяти в разных ядрах процессора, если это не затребовано разработчиком явно, или неявно через многопоточные примитивы.

Заключение

Сложно представить современную C++ программу, которая была бы однопоточной. Опасно писать многопоточные программы, не имея представления о правилах синхронизации памяти. Я считаю, что нужно знать как работают атомики в C++. Чтобы не совершать ошибок типа volatile bool, чтобы понимать какие изменения в каких потоках будут видны после использования того или иного многопоточного примитива, чтобы использовать read-modify-write атомарные операции вместо мьютекса, там где это возможно. Данная статья помогла мне систематизировать материал, который я находил в разных источниках и освежить знания в памяти. Надеюсь, она поможет и вам!

Источники

[1] Anthony Williams. C++ Concurrency in Action. https://www.amazon.com/C-Concurrency-Action-Practical-Multithreading/dp/1933988770

[2] Tony van Eerd. C++ Memory Model & Lock-Free Programming. https://www.youtube.com/watch?v=14ntPfyNaKE

Система логирования ALog первоначально разрабатывалась для использования в серверных приложениях. Первая реализация ALog была выполнена в 2013 году, на тот момент я и подумать не мог, что спустя семь лет буду писать про нее статью на Хабр. Но, видимо, на все воля случая Сейчас уже и не вспомню, что именно искал на просторах интернета, когда мне на глаза попалась статья Сравнение библиотек логирования. Я решил бегло просмотреть её в ознакомительных целях. По мере знакомства с материалом в голове возникла мысль: "А где же в этом 'табеле о рангах' находится мой логгер?". Чтобы это выяснить был создан небольшой проект LoggerTest для тестирования систем логирования.

Асинхронный логгер

Прежде чем переходить к тестам, нужно сказать пару слов про ALog¹. Это асинхронная система логирования, предназначенная для использования в высоконагруженных многопоточных приложениях. Как правило, подобные приложения работают на серверных станциях, что определяет специфику самого логгера. По большому счету особенностей две:

0. У логгера нет ограничения по памяти (обычно серверы не испытывают недостатка в ОЗУ) ²

1. Стоимость вызова логгера в рабочих потоках должна быть минимальной. Данная характеристика важна для любой программы, но для серверной - особенно, где стоимость процессорных ресурсов может быть достаточно высока.

[1] ALog не является самостоятельной библиотекой, это всего лишь несколько модулей в составе библиотеки общего назначения.

[2] Использование ALog в ситуациях отличных от тестовых не приводит к существенному потреблению оперативной памяти, что позволяет использовать логгер на ARM-системах с небольшим объемом ОЗУ.

Участники тестирования

Первоначально для сравнения была выбран только Spdlog. Это было сделано по нескольким причинам:

0. В исходной статье Spdlog показал неплохие результаты - фактически второе место;

1. Логгер асинхронный (синхронные логгеры меня не интересовали в принципе, по причине их низкой производительности в многопоточных приложениях);

2. Под впечатлением от статьи, P7 казался просто недосягаемым, поэтому вначале я его даже не рассматривал в качестве участника тестирования.

Первые сравнения были сильно не в пользу ALog. Пришлось заняться оптимизацией, благо было понимание какие механизмы могут тормозить работу логгера. В итоге отставание стало не столь катастрофическим. Воодушевленный результатом, я написал автору статьи Сравнение библиотек логирования о своем логгере, и приложил первые тесты. Но реакции на мое сообщение не последовало. Выдержав паузу в пару месяцев, я решил самостоятельно написать о проделанной работе.

Для тестов было отобрано три логгера::

0. G3log (версия 1.3.3, gitrev: f1eff42b)

1. P7 (версия 5.5)

2. Spdlog (версия 2.x, gitrev: f803e1c7)

G3log был добавлен просто для статистики. У этого логгера не очень высокая скорость сохранения данных на диск, что и было подтверждено тестами. Последним в сравнение был включен P7. Хочу сказать спасибо разработчикам P7, за помощь в написании тестового примера.

Формат тестовых сообщений

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

У Spdlog и G3log формат префикса можно менять, что позволяет сделать лог-сообщения похожими на сообщения ALog, и таким образом обеспечить примерно одинаковый объем записываемой информации.

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

Внешний вид префиксов для лог-сообщений:

• ALog ----------------------------------------------------- 15.10.2020 19:39:23.981457 DEBUG2 LWP18876 [alog_test.cpp:35 LoggerTest]

• Spdlog ---------------------------------------------------[2020-10-15 20:22:55.165] [trace] LWP19519 [spdlog_test.cpp:76 LoggerTest]

• G3log -----------------------------------------------------2020/10/15 20:24:48 836329 DEBUG [g3log_test.cpp->thread_func:36]

Тестовый стенд

• OS: Ubuntu 20.04

• Compiler: GCC 8.4.0 C++14

• CPU: Intel Core i7 2700K, 4 ядра, 8 потоков (4.5GHz, разгон)

• RAM: 32Gb (DDR3-1600, XMP 8-8-8-24-2N)

• SSD: Samsung 860 Pro 512Gb³

• Количество итераций в тесте: 5

• Количество записываемых строк: 5 000 000

[3] Любопытный момент: скорость сохранения логов на HDD диск (TOSHIBA HDWD120) оказалась выше чем на SSD.

Тестирование

В тестах проводится замер четырех характеристик. Две из них являются прямыми, то есть непосредственно определяют эффективность работы логгера. Оставшиеся две - косвенные. По сути, косвенные характеристики обратно пропорциональны прямым. На мой взгляд, они интересны с оценочной точки зрения, но как таковые не отражают эффективность системы логирования.

Прямые характеристики:

• Logging time - усредненное время, за которое все тестовые сообщения будут добавлены в систему логирования;

• Flush time - усредненное время, за которое все тестовые сообщения будут сохранены на диск (это время отсчитывается от начала теста, поэтому включает в себя значение Logging time).

Косвенные характеристики:

• Memory usage (max/average) - пиковое и среднее потребление памяти логгером в тесте (берутся худшие показатели из выполненных итераций);

• CPU usage (max/average) - пиковое и среднее потребление ресурсов процессора. За 100% принимается полная загрузка одного ядра процессора (берутся худшие показатели из выполненных итераций).

Дополнительные условия:

0. В P7 размер пула был установлен в 1 Гб (/P7.Pool=1048576). Для P7 это абсолютно сверх меры, но все участники на старте должны иметь более-менее одинаковые условия;

1. Для Spdlog размер очереди установлен в 3 млн. сообщений. Уменьшение её размера будет сказываться на показателе Logging time. Логгер работает в режиме async_overflow_policy::block, что запрещает ему отбрасывать "старые" сообщения если очередь переполнена.

Тест 4 потока (режим сборки: release, ключ компилятора -O2)

По параметру Flush time ALog так и не смог опередить Spdlog. Поэтому можно сказать, что по Flush time Spdlog - лидер. Правда тут есть одна оговорка: это преимущество сохраняется до тех пор, пока размер очереди больше либо равен 3 * 10^6. "Ложка дегтя" заключается в том, что память под очередь сообщений выделяется в момент создания Spdlog, и остается занятой на всем протяжении работы логгера. В данном тесте Spdlog использовал 1170Мб. Остальные участники тестирования выделяют память по мере повышения нагрузки, и освобождают по мере понижения.

Тест 4 потока (режим сборки: debug, ключ компилятора -O0)

Тест в debug-режиме интересен с точки зрения падения производительности. Очевидно, что проседание есть, но оно не такое катастрофическое (десятки раз), как об этом говорится в Сравнение библиотек логирования. Возможно, причина в том, что тесты проводились на Linux.

Тест 1 поток (режим сборки: release, ключ компилятора -O2)

В этом тесте P7 восстановил свой статус-кво. Запись в систему логирования 5 млн. сообщений в один поток за ~1.9 секунды выглядит просто недосягаемо! Скорость сохранения данных на диск тоже весьма впечатляет.

Здесь ALog уступает Spdlog в Logging time. Valgrind по этому поводу "говорит", что одна из причин низкой производительности кроется в использовании функции std::vsnprintf(). При сборке тестов под С++17 появляется возможность минимизировать использование std::vsnprintf(). При этом Spdlog все еще впереди, но отставание уже минимально (~0.15 сек). В то же время ALog улучшает другие показатели: максимальный объем занимаемой памяти уменьшился до 44 Мб, а пиковое потребление ресурсов процессора сократилось до 33%.

Для Spdlog размер очереди сообщений уменьшен до 1 млн. записей, что позволило сократить объем занимаемой памяти с 1170 Мб до 392 Мб. Дальнейшее уменьшение размера очереди ведет к ухудшению Logging time. Еще один штрих: сборка Spdlog под С++17 даёт незначительное (примерно на 0.1 секунды) увеличение Logging time, не затрагивая остальные результаты.

Промежуточный итог

Что ж, тщеславие удовлетворено. Пусть ALog не первый в этом тестировании, но тем не менее выглядит вполне достойно, а по параметру Logging time в многопоточном режиме работы - безусловный лидер.

Но что же дальше?! Эффективность работы системы логирования безусловно важна, но есть и другие критерии, которые целесообразно принимать во внимание. Например: возможность конфигурирования, фильтрация, удобство записи лог-сообщений в рабочем коде. Уже в процессе подготовки тестов пришла мысль, что наверное не следует ограничиваться только сравнением логгеров, и было бы неплохо рассказать об особенностях использования ALog. Это я и собираюсь сделать в следующих разделах.

Немного плагиата

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

Документация и зависимости

Документация: отсутствует, к сожалению. Что бы сгладить этот недостаток, был создан небольшой проект LoggerDemo с примерами использования логгера. Сейчас их шесть:

• Demo 01: Вывод в лог "Hello world";

• Demo 02: Вывод сообщений в файл;

• Demo 03: Вывод сообщений из разных потоков;

• Demo 04: Фильтрация лог-сообщений по имени модуля, с последующим сохранением в разные лог-файлы;

• Demo 05: Конфигурирование лог-системы при помощи конфиг-файлов⁴;

• Demo 06: Форматированный вывод через log_format (тестовое использование)

Для сборки потребуется QtCreator 4.12 или выше. Сборочная система QBS.

Примечание: сборка под ОС Windows не выполнялась, но проект тривиален, поэтому проблем возникнуть не должно.

Зависимости: ALog - не самостоятельное решение, он является составной частью библиотеки общего назначения SharedTools. Для такого подхода есть пара причин:

• ALog достаточно маленький - всего три программных модуля⁵:

  0. logger - непосредственно сам логгер;

  1. config - модуль конфигурирования;

  2. format - модуль для форматированного вывода сообщений.

• ALog зависит от некоторых модулей общего назначения из SharedTools. Поэтому я посчитал нецелесообразным выносить логгер в отдельную библиотеку, и делать ее зависимой от SharedTools.

[4] Для сборки примера Demo 5 требуется Qt-framework.

[5] Под программным модулем понимается пара cpp/h файлов, или один h-файл.

Тип логгера, контроль потребления памяти и потокобезопасность

• Логгер асинхронный, порядок добавления сообщений можно считать атомарным (используется спин-блокировка), что не исключает возможности перемешивания сообщений. Однако, для диапазона точности, в котором работает логгер (микросекунды), явления перемешивания вряд ли могут быть обнаружены. За семь лет использования логгера я не сталкивался с подобными проявлениями.

• Контроль потребления памяти отсутствует.

Обработка сбоев процесса

Автоматическая обработка сбоев процесса не предусмотрена. Считаю, что программист должен самостоятельно выполнять такого вида обработки, так как сложно предвидеть все инварианты, которые могут потребоваться разработчику. Тем не менее, существует механизм для немедленного "сброса" всех сообщений из буфера логгера в систему вывода. Функция "сброса" сообщений может выглядеть так:

void prog_abort(){    log_error << "Program aborted";    alog::logger().flush();    alog::logger().waitingFlush();    alog::logger().stop();    abort();}

Стиль логирования и вывод (sink)

Вывод (sink): В ALog механизм вывода называется Saver (дословно: хранитель, в вольной трактовке: средство/механизм сохранения). В дальнейшем будет использоваться именно этот термин.

По умолчанию поддерживаются вывод в файл, и в stdout. В качестве демо-примера, сделан вывод в syslog. Правда, на момент его написания, syslog не мог похвастаться высокой скоростью работы, конечно с той поры может что и поменялось.

Стиль логирования: ALog поддерживает два стиля логирования: потоковый оператор << и форматированный вывод. При этом, вывод через потоковый оператор является основным, а форматированный вывод был добавлен сравнительно недавно и, на текущий момент, находится в статусе экспериментальный.

Споры о том, какой способ вывода лучше не закончатся наверное никогда. На мой взгляд, у потокового оператора есть одно важное преимущество: его можно переопределять, что позволяет системе логирования работать с пользовательскими типами данных. А возможность выводить лог-сообщения сразу через несколько saver-ов добавляет системе логирования ещё больше гибкости.

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

Используем структуру TaskLog для группировки необходимых параметров логирования.

struct TaskLog{    int taskId;    int userId;    string status;};

На следующем шаге реализуем потоковый оператор ⁶.

namespace alog {Line& operator<< (Line& line, const TaskLog& tl){    if (line.toLogger())        line << "TaskId: "   << tl.taskId             << "; UserId: " << tl.userId             << "; Status: " << tl.success;    return line;}} // namespace alog

Реализацию saver-a для записи сообщений в базу данных я оставлю за рамками этой статьи по причине существенного объема кода. Отмечу только, что saver нужно будет создать и зарегистрировать в системе логирования при старте программы. Далее в рабочем коде приложения вызываем логгер:

TaskLog tl {10, 20, "success"};log_info << "Task complete. " << tl;

В лог-файл будет добавлена строка: 15.10.2020 19:39:23 INFO LWP18876 [example.cpp:35] Task complete. TaskId: 10; UserId: 20; Status: success И одновременно с этим система логирования вставит в таблицу базы данных запись из трех полей: TASK_ID, USER_ID, STATUS. Конечно, реализация потокового оператора и saver-a для вывода информации в базу данных потребует определенных усилий, но это может быть оправдано удобством последующего использования.

Вот еще одна ситуация, которую хотелось бы рассмотреть: иногда лог-сообщение должно формироваться в зависимости от условия. "Классический" способ решения этой задачи - конкатенация строк с последующим выводом результата. В ALog конкатенация может быть заменена на последовательное формирование лог-сообщения при помощи явно объявленной переменной с типом alog::Line:

{ //Block for alog::Line    alog::Line logLine = log_verbose << "Threshold ";    if (threshold > 0.5)        logLine << "exceeded";    else        logLine << "is normal";    logLine << " (current value: " << threshold << ")";}

Форматированный вывод реализован как надстройка над потоковыми операторами. Таким образом форматированный вывод будет работать со всеми типами данных для которых реализован оператор <<. Пример с выводом TaskLog будет выглядеть так:

TaskLog tl {10, 20, "success"};log_info << log_format("Task complete. %?", tl);

Возможно комбинирование потоковых операторов и форматированного вывода:

log_info << "Task complete." << log_format(" %?", tl);

[6] В примере приведена базовая (упрощенная) реализация потокового оператора.

Инициализация логгера

ALog поддерживает два вида инициализации: программную, и с использованием конфигурационных файлов. Инициализация является потокозащищенной, что позволяет реконфигурировать систему логирования в любой момент работы приложения.

Для stdout программная инициализация состоит из одной строки:

alog::logger().addSaverStdOut(alog::Level::Info);

Инициализация для вывода в файл будет чуть сложнее:

const char* saverName = "default";const char* filePath = "/tmp/logger-demo.log";alog::Level logLevel = alog::Level::Debug;bool logContinue = true;{ //Block for SaverPtr    SaverPtr saver {new SaverFile(saverName, filePath, logLevel, logContinue)};    logger().addSaver(saver);}

Для небольших приложений программная инициализация достаточно эффективна. Но по мере роста приложения, по мере усложнения конфигурации логирования, такая инициализация становится громоздкой, и в конечном счете неудобной для использования. Поэтому для больших приложений предпочтительнее будет инициализация с использованием конфигурационных файлов. Работа с файлами конфигурации требует наличия yaml-парсера. ALog для этой цели использует yaml-cpp.

Пример секции инициализации логгера:

### YAML syntax #### Конфигурирование системы логированияlogger:    # Уровень логирования. Допускаются следующие значения: error, warning, info,    # verbose, debug, debug2. По умолчанию используется info    level: verbose        # Определяет будет ли пересоздаваться log-файл при перезапуске программы.    # (флаг: true/false). Если параметр равен 'false', то log-файл будет    # пересоздаваться при каждом перезапуске программы, в противном случае    # логирование будет выполняться в существующий файл    continue: true        # Наименование файла логирования    file: /var/opt/application/log/application.log        # Наименование файла логирования в Windows    file_win: ProgramData/application/log/application.log        # Определяет файл конфигурирования сейверов и фильтров для системы логирования    conf: /etc/application/application.logger.conf        # Определяет файл конфигурирования сейверов и фильтров для системы логирования в Windows    conf_win: ProgramData/application/config/application.logger.conf        filters:        # Наименование фильтра      - name: default        type: module_name        mode: exclude            modules: [            VideoCap,            VideoJitter,        ]

В этой конфигурации будет создан saver по умолчанию⁷, с выводом в файл /var/opt/application/log/application.log. Параметры logger.conf и logger.filters отвечают за механизмы расширенной фильтрации, их назначение будет рассмотрено в разделе Настройка фильтрации.

В примере Demo 05 показано как создается saver по умолчанию с использованием файла конфигурации. А пример ниже демонстрирует, как можно переконфигурировать систему логирования в процессе работы программы:

// Время последней модификации конфиг-файла приложенияstd::time_t configBaseModify = 0;// Время последней модификации конфиг-файла для логераstd::time_t configLoggerModify = 0;void init(){    // Время модификации файлов на момент старта программы    configBaseModify = config::baseModifyTime();    configLoggerModify = config::loggerModifyTime();}// Таймер-функцияvoid configModifyTimer(){    bool modify = false;    std::time_t configModify = config::baseModifyTime();    if (configBaseModify != configModify)    {        modify = true;        configBaseModify = configModify;        config::base().rereadFile();        log_verbose << "Config file was reread: " << config::base().filePath();        alog::configDefaultSaver();    }    configModify = config::loggerModifyTime();    if (configLoggerModify != configModify)    {        modify = true;        configLoggerModify = configModify;        alog::configExtensionSavers();    }    if (modify)        alog::printSaversInfo();}

[7] Наименование saver-a по умолчанию всегда 'default'

Точность времени

Все сообщения в ALog фиксируются с точностью до 1 микросекунды, что покрывает потребности большинства существующих приложений. Но выводится это время только при уровне логирования Debug2 (режим трассировки). Такая точность временных меток необходима для режима подробной диагностики, для менее интенсивных режимов логирования вполне достаточно точности в 1 секунду. Данный подход несколько сокращает объем лог-файла. При разработке собственного saver-a разработчик может выводить микросекунды на любом уровне логирования.

Доступ к логгеру

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

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

Настройка фильтрации

ALog, как и большинство современных логгеров, поддерживает фильтрацию по уровням логирования. Имеются следующие варианты:

enum Level {None = 0, Error = 1, Warning = 2, Info = 3, Verbose = 4, Debug = 5, Debug2 = 6};

Debug2 - соответствует режиму трассировки, название имеет исторические причины.

На этом, сходство с другими логгерами заканчиваются. Первое существенное отличие состоит в том, что для ALog невозможно задать уровень логирования напрямую, так как уровень логирования - не характеристика логгера, а характеристика его saver-ов. Уровень логирования самого логгера всегда будет равен максимальному уровню логирования saver-ов, использующихся на данный момент. Однако, для логгера эта характеристика тоже достаточно важна, так как она позволяет еще на первичном этапе обработки сообщений отсекать те из них, которые гарантированно не будут выводиться в лог.

Чтобы перейти к следующим отличиям, нам придется более подробно рассмотреть как используются уровни логирования. Типовая задача - выявление ошибок или аномального поведения, проявляющегося при длительной работе программы. Для решения этой задачи систему логирования переводят в режим отладки или трассировки, и затем ждут проявления негативной ситуации. У такого подхода есть следующие недостатки:

0. При использовании глобального логгера все программные модули будут выдавать сообщения с заданным уровнем логирования, в результате чего получается много лишней, избыточной информации;

1. Использование нескольких экземпляров логгера в попытке уйти от проблемы из п.1 выглядит не очень удачной идеей. На мой взгляд, система логирования должна быть простой и единообразной в использовании из любой части программы. Программист не должен задумываться над тем, каким экземпляром логгера ему пользоваться;

2. Объем файлов логирования может быть очень большим (см. п.1). Иногда объемы лог-файлов исчисляются десятками гигабайт, то есть существует риск отказа операционной системы из-за отсутствия свободного места на диске;

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

Возникает очевидная мысль: "Нужно сократить объем записываемой информации". Например, P7 решает эту задачу посредством вывода лог-сообщений в бинарном формате. На самом деле неизвестно - является ли это эффективным решением проблемы, так как большинство утилит по анализу логов ориентированы на текстовый формат данных.

Тогда возникает вторая мысль: "Нужно сделать так, чтобы разные модули программы могли выдавать лог-сообщения с разным уровнем логирования". При диагностике программы, как правило, уже имеются предположения о том, какие её узлы могут приводить к сбою. Соответственно, только эти узлы должны выдавать максимально подробные логи, а остальные части программы могут работать со штатным уровнем логирования. Как выводить такую гетерогенную лог-информацию? Возможны два подхода:

0. Все модули, со штатными и трассировочными уровнями логирования пишут свои сообщения в один файл. Таким образом сохраняется последовательная хронология событий;

1. Существует один главный файл логирования, в который пишут все модули в режиме штатного логирования, и одновременно модули требующие диагностики пишут свои лог-сообщения в альтернативные файлы в режиме трассировки.

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

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

Под логическим модулем понимается один или несколько программных модулей объединенных общим функционалом или выполняемым действием.

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

Более подробно типы фильтрации описаны тут. Файл demo05.logger.conf содержит пример конфигурации логгера для Demo 05

Осталось рассмотреть вопрос с наименованием логических модулей. Можно использовать решение "в лоб", но выглядит оно не очень

alog::logger().debug(alog_line_location, "Module1") << "Message";

Как часто бывает в таких ситуациях - на помощь приходят макросы.

// Определяем макросы в начале модуля#define log_error_m   alog::logger().error   (alog_line_location, "Module1")#define log_warn_m    alog::logger().warn    (alog_line_location, "Module1")#define log_info_m    alog::logger().info    (alog_line_location, "Module1")#define log_verbose_m alog::logger().verbose (alog_line_location, "Module1")#define log_debug_m   alog::logger().debug   (alog_line_location, "Module1")#define log_debug2_m  alog::logger().debug2  (alog_line_location, "Module1")...void moduleFunc1(){    for (int i = 0; i < 10; ++i)    {        log_debug_m << "Func1. Message " << i;        usleep(10);    }}...// Удаляем макросы в конце модуля#undef log_error_m#undef log_warn_m#undef log_info_m#undef log_verbose_m#undef log_debug_m#undef log_debug2_m

В cpp-файлах #undef можно опустить, но не стоит так делать в заголовочных файлах. В этом случае результат работы лог-фильтров может оказаться неожиданным.

Поддержка юникода

Фактически, широкой поддержки юникода нет. В Linux в подавляющем большинстве ситуаций используется UTF-8. Для QString есть перегруженный потоковый оператор, в нем осуществляется преобразование из UTF-16 в UTF-8. На этом все.

Ротация файлов

ALog не поддерживает какие либо механизмы по ротации лог-файлов, так как с этой задачей прекрасно справляется logrotate.

Некоторые приемы использования

Здесь описаны некоторые приемы использования ALog, которые не попали в другие разделы. Делаю это на тот случай, если вдруг кому-то в голову придет мысль о применении ALog в своей программе.

Сложные трассировочные сообщения лучше использовать внутри условия:

if (alog::logger().level() == alog::Level::Debug2){    log_debug2_m << "Message was sent to socket"                 << ". Id: " << message->id()                 << ". Command: " << CommandNameLog(message->command())                 << ". Type: " << message->type()                 << ". ExecStatus: " << message->execStatus();}

Обычно трассировочные сообщения размещаются в высоконагруженных участках кода. По этой причине их целесообразно полностью исключать из обработки, когда программа работает не в режиме отладки. Это позволит не тратить ресурсы на формирование сложного сообщения, которое в конечном итоге все равно будет отброшено. В тоже время для тривиальных сообщений вполне можно обойтись без дополнительных условий:

log_debug2_m << "Message was sent to socket";

Наименование программного модуля получено из другой программы

std::string s = ".../python/example1.py";const char* file = alog::__file__cache(s);alog::logger().info(file, 0, 10, "Python") << "Message from python-script";

Не так давно в ALog была добавлена оптимизация позволяющая извлекать наименование программного модуля из макроса __FILE__ в процессе компиляции, и это реально ускорило работу логгера. Но у такой оптимизации есть обратная сторона: адреса строк содержащих наименования модулей не должны меняться на протяжении жизни программы. В принципе, с макросом __FILE__ все так и есть. Но иногда возникает желание (или необходимость) сделать сквозное логирование для внутренних и внешних (работающих в другом процессе) компонентов приложения. В данном случае наименования модулей получаемые из внешней программы имеют динамические адреса строк, а следовательно их нельзя передавать в ALog. Для решения этой проблему была создана функция alog::__file__cache(), она преобразует динамические строки в псевдостатические, что вполне устраивает логгер.

Подмена механизма логирования в сторонних библиотеках Многие сторонние библиотеки имеют свой механизм логирования. Иногда это полноценная система логирования, но чаще - это просто функция. Для обеспечения единообразного логирования собственного проекта можно попробовать сделать подмену библиотечной функции логирования⁸. При этом стороннюю библиотеку, скорее всего, придется собрать самостоятельно, или как минимум, нужно быть готовым к такому повороту событий.

Пример подмены функции логирования logmvnc() для драйвера Intel Movidius Neural Compute Stick:

void logmvnc(enum mvLog_t level, const char* file, int line, const char* func,             const char* format, ...) asm ("logmvnc");void logmvnc(enum mvLog_t level, const char* file, int line, const char* func,             const char* format, ...){    va_list args;    va_start(args, format);    int len;    char buff[1024] = {0};    auto removeLastN = [&len, &buff]()    {        if ((len < int(sizeof(buff))) && (buff[len - 1] == '\n'))            buff[len - 1] = '\0';    };    switch (level)    {        case MVLOG_DEBUG:            if (alog::logger().level() == alog::Level::Debug2)            {                len = vsnprintf(buff, sizeof(buff) - 1, format, args);                removeLastN();                alog::logger().debug2(file, func, line, "Movidius") << buff;            }            break;        case MVLOG_WARN:            {                len = vsnprintf(buff, sizeof(buff) - 1, format, args);                removeLastN();                alog::logger().warn(file, func, line, "Movidius") << buff;            }            break;        case MVLOG_ERROR:        case MVLOG_FATAL:        case MVLOG_LAST:            {                len = vsnprintf(buff, sizeof(buff) - 1, format, args);                removeLastN();                alog::logger().error(file, func, line, "Movidius") << buff;            }            break;        default:            {                // LEVEL_INFO                len = vsnprintf(buff, sizeof(buff) - 1, format, args);                removeLastN();                alog::logger().info(file, func, line, "Movidius") << buff;            }    }    va_end(args);}

[8] Это возможно не для всех библиотек.

Вместо заключения

Когда я только начинал работу над этим материалом, то полагал, что ALog уже достаточно устоявшееся, отработанное решение. Но мои представления были неверными. Оказалось, что есть много аспектов, требующих переоценки или доработки. Какие-то правки вносились в процессе тестирования, а какие-то уже в процессе написания этой статьи. Благодаря всей этой затее были созданы два новых проекта: LoggerTest и LoggerDemo. Оба проекта открыты для развития, поэтому если у кого-то возникнут вопросы по работе логгера - постараюсь, по мере возможности, на них ответить. Может быть ответы воплотятся в новых примерах. Касательно LoggerTest - думаю, я далеко не единственный, кто пишет свой логгер, так что если есть желание помериться цифирьками - приходите.

Давайте представим, что вы параноик, и параноик вдвойне, когда дело касается многопоточности. Предположим, что вы делаете backend некого функционала приложения, а приложение переодически дергает на вашем серверы какие-то методы. Все вроде хорошо, но есть одно но. Что если ваш функционал напрямую зависит от каких-либо других данных, того же банального профиля например? Встает вопрос, как гарантировать то, что сценарий отработает именно так, как вы планировали и не будет каких-либо сюрпризов? Транзакции? Да это можно использовать, но что если Вы фантастический параноик и уже представляете как к вам на сервер летит 10 запросов к одному методу от разных клиентов и все строго в одно время. А в этот момент бизнес-логика данного метода завязана на 100500 разных данных. Как всем этим управлять? Можно просто синхронизировать метод и все. Но что если летят еще и те запросы, держать которые нет смысла? Тут уже начинаются костыли. Я пару раз уже задавался подобным вопросом, и были интересно, ведь задача до абсурда простая и повседневная (если вы заботитесь о том, чтобы не было логических багов конечно же :). Сегодня решил подумать, как это можно очень просто и без костылей реализовать. И решение вышло буквально на 100 строк кода.

Немного наглядного примера

Давайте предположим, что есть водитель и есть пассажир. Водитель не может менять машину до тех пор, пока клиент, например подтверждает поездку. Это что получается, клиент соглашался на поездку с одними характеристиками машины, а по факту у водителя другая машина? Не дела! Можно организовать что-то подобное:

String result = l.lock(new ArrayList<Locker.Item>() {{    add(new Locker.Item(SimpleType.TRIP, 1));    add(new Locker.Item(SimpleType.USER, 2));}}, () -> {    // Тут выполняем отмену поездки и держим водителя на привязи    // Кстати если кто-то где-то вызовет USER=2 (водитель), то он также будет ждать    // ну или кто-то обратится к поездке TRIP=1    // А если обратится к USER=3, то уже все будет нормально :)    // так как никто не блокировал третьего пользователя :)    return "Тут любой результат :)";    });

Элегантно и просто! :)

Исходники тут - https://github.com/GRIDMI/GRIDMI.Sync

Камнями не бросаться! :)

Сегодня я расскажу вам про довольно простую, но интересную реализацию многопоточности в HTTP-сервере без создания потока для каждого клиента. На мое удивление информацию про такую реализацию я нашёл с трудом, поэтому решил поделиться с вами. Начнем с описание проблемы.

Проблемы решения "один поток = один клиент"

Проблемы, которые описаны ниже, справедливы как для потоков, так и для процессов, поэтому "один поток = один клиент" также можно расценивать как и "один процесс - один клиент" в данном контексте.

Первая проблема - количество потоков, которые могут быть созданы в программе, ограничено. Следствием этого ограничено и количество пользователей, подключённых к нашему серверу. Такая проблема есть, например, у Apache.

Проблема вторая - один поток занят только одним клиентом. В связи с этим мы получаем неэффективное использование ресурсов. (поток может простаивать, пока ждёт события от клиента)

Плюсом ко всему этому нужно понимать, что создание потока (или процесса) - это довольно тяжелая операция, и иногда она требует затрат больше, чем само обслуживание клиента.

Решение, которое я приведу ниже, закрывает эти проблемы.

Решение есть

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

Вторая проблема закрывается тем, что потоки не прикреплены к клиентам. Фактически, обслуживание клиента разбивается на задачи, которые решают потоки. Таким образом, мы избавляемся от простоев потоков, если работа для них есть.

Конечный автомат

Первое, что нам понадобится, ввести состояние клиента. Таким образом поток (далее, воркер) будет знать, какой хэндлер нужно вызвать для текущего состояния. Хэндлером может выступать метод, который выполняет характерные для состояния действия. После обработки очередного состояния мы, в зависимости от условий, меняем его.

На каждое состояние у нас есть свой хэндлер. Рассмотрим пример. У клиента четыре состояния: readRequest, generateResponse, sendResponse и closeConnection (чтение запроса, создание ответа, отправка ответа и закрытие соединения, соответственно). На каждое состояние мы имеем хэндлер. readRequest читает и парсит запрос и, в зависимости от успеха чтения и парсинга (например, в зависимости от того, что вернула функция чтения запроса), переключает состояние либо на generateResponse, либо на closeConnection. generateResponse отвечает за генерацию ответа и переключает состояние клиента на sendResponse. sendResponse отправляет ответ клиенту и либо возвращет клиента на состояние readRequest, либо переключает на closeConnection. closeConnection, в свою очередь, просто отключает клиента и удаляет его.

Этот примитивный пример показывает суть принципа. Мы можем добавлять новые состояния клиентов (причем в коде делается это довольно просто: мы просто реализуем новый метод) и переключать их как угодно в зависимости от условий. Вы можете с легкостью разбивать состояние на два отдельных, если чувствуете в этом необходимость. В нашем примере парсинг запроса включен в состояние readRequest и его можно вынести в отдельное состояние - parsingRequest, например.

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

Довольно неплохая лекция на тему конечных автоматов. Также информации об этом методе в интернете полно, поэтому заострять внимание на деталях мы не будем.

ThreadPool (или пул потоков)

Пул потоков как таковым пулом потоков не является. Скорее он представляет собой пул (в виде очереди, например) задач для этих потоков.

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

Если наш клиент отправил нам только часть запроса, поток в сервере формата "один клиент=один поток" будет ожидать оставшуюся часть запроса. (то есть простаивать) В нашем же случае поток обработает часть запроса и пойдет обрабатывать следующих клиентов, если такие есть (простаивания потока не происходит).

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

Заключение

Как я уже упомянул выше, решение довольно простое и, возможно, его не стоит брать в качестве основы для реализации, но этот вариант отлично подойдёт как шаблон, который можно усовершенствовать и подстроить под себя и свою задачу.

В этот раз я в общих чертах рассказал только про суть подхода. Если вам интересно увидеть продолжение статьи уже с практической частью (подходы к реализации и их подводные камни) - дайте знать об этом:)

На этом все. Делитесь своими вариантами, предложениями, дополнениями и критикой в комментариях! Благодарю за прочтение:)

Несколько полезных ссылок:

http://personeltest.ru/aways/habr.com/ru/post/260065/

http://personeltest.ru/aways/habr.com/ru/company/latera/blog/273283/

http://www.aosabook.org/en/nginx.html