async_logging.rb

async_log.rb

require 'logging'
require 'concurrent-edge'
require 'securerandom'

LOG_LAYOUT = Logging.layouts.pattern(
  pattern: %w(%X{platform_tid} %X{account_name} %X{account_id} %m\n).join(' '),
)

Logging.logger.root.add_appenders Logging.appenders.stdout(layout: LOG_LAYOUT)

$jobs = []

N_THREADS = (ARGV[0] || 20).to_i
N_PROMISES = (ARGV[1] || 20).to_i

class MyExecutor

  def call(id, promise_id, platform_tid, account_name, account_id)
    sleep rand
    Logging.logger[self].info "#{Thread.current.object_id} #{platform_tid} #{account_name} #{account_id} MyExecutor:: promise #{promise_id} with id #{id}"

    logger_context_store = Logging.mdc.context.dup
    $jobs << Concurrent::Promises.future do
      sleep rand
      #Logging.mdc.inherit(logger_context_store)
      logger_context_store.each_key { |key| Logging.mdc[key] = logger_context_store[key] }
      sleep rand
      Logging.logger[self].info "#{Thread.current.object_id} #{platform_tid} #{account_name} #{account_id}  Concurrent::Promises:: promise #{promise_id} with id #{id}"
      end
  end
end


class Logger2

  def run
    threads = []

    (1..N_THREADS).each do |n|
      threads << Thread.new {
        platform_tid = SecureRandom.uuid
        account_id = SecureRandom.uuid
        account_name = SecureRandom.uuid

        Logging.mdc[:platform_tid] = platform_tid
        Logging.mdc[:account_id] = account_id
        Logging.mdc[:account_name] = account_name

        (1..N_PROMISES).each do |t|
          MyExecutor.new.call(n, t, platform_tid, account_name, account_id)
        end
      }
    end

    threads.each {|t| t.join}
    Concurrent::Promises.zip(*$jobs).wait!
  end
end


Logger2.new.run


## Results
# for i in {1..100}; do ruby async_log.rb 40 40 > results.txt && cat results.txt | awk -F " " '{if ($1!=$5||$2!=$6||$3!=$7) print $0}' | wc -l; done
# line #25 uncommented and #26 commented and 40 threads/40 promises: avg of 1465,29 of 1600 divergent log entries
# line #25 commented and #26 uncommented and 40 threads/40 promises: avg of 0 of 1600 divergent log entries