Odtnhj

I use the logstasher gem to convert my logs into json objects
then I add a line before each log line,
in development everything works fine.
In production sometimes the lines change places.

this is how it should be

"index":"_id":"3cc6221b633bd2bd0a95865e9c0c3dfd"
"method":"GET","path":"/public/so_list","format":"*/*","controller":"public","action":"so_list","status":200,"duration":3152.27,"view":246.58,"db":2882.97,"ip":null,"route":null,"request_id":null,"source":"unknown","tags":["request"],"@timestamp":"2018-11-15T18:53:36Z","@version":"1"
"index":"_id":"4b94f72318d88a8d7c1c5e46e5465246"
"method":"GET","path":"/public/ajx_group_items/DY2149","format":"*/*","controller":"public","action":"ajx_group_items","status":200,"duration":118.89,"view":31.89,"db":74.0,"ip":null,"route":null,"request_id":null,"source":"unknown","tags":["request"],"@timestamp":"2018-11-15T18:53:36Z","@version":"1"
"index":"_id":"b1ceb09e59379be7e26bff6b0d91ccd9"
"method":"GET","path":"/public/login","format":"html","controller":"public","action":"login","status":200,"duration":44.24,"view":41.55,"db":1.25,"ip":null,"route":null,"request_id":null,"source":"unknown","tags":["request"],"@timestamp":"2018-11-15T18:53:36Z","@version":"1"

and sometimes happens this

line 2 should change places with line 3

"index":"_id":"f6ee3d21d6e424652cdca28e9fdff611"
"index":"_id":"3c5050daede3f29d0402e888eef02046"
"method":"GET","path":"/public/ajx_group_items/DY7100","format":"*/*","controller":"public","action":"ajx_group_items","status":200,"duration":341.08,"view":169.3,"db":157.56,"ip":null,"route":null,"request_id":null,"source":"unknown","tags":["request"],"@timestamp":"2018-11-15T18:53:37Z","@version":"1"
"method":"GET","path":"/public/ajx_group_items/DY7000","format":"*/*","controller":"public","action":"ajx_group_items","status":200,"duration":334.34,"view":191.42,"db":129.59,"ip":null,"route":null,"request_id":null,"source":"unknown","tags":["request"],"@timestamp":"2018-11-15T18:53:37Z","@version":"1"
"index":"_id":"f6f59814f6cd45851d529a4efd1d5989"
"method":"GET","path":"/public/ajx_group_items/DY7210","format":"*/*","controller":"public","action":"ajx_group_items","status":200,"duration":305.02,"view":221.0,"db":72.51,"ip":null,"route":null,"request_id":null,"source":"unknown","tags":["request"],"@timestamp":"2018-11-15T18:53:37Z","@version":"1"

my initializer looks like that

if LogStasher.enabled?

 LogStasher::ActiveSupport::LogSubscriber.class_eval do

 alias :original_process_action :process_action

 def process_action(event)

 # this creates the first line before each log
 log_extra_line = Logger.new("#Rails.root/log/logstasher.log")
 hash = index: _id: event.payload[:request_id]
 log_extra_line.info(hash.to_json) 

 # this adds the log line
 original_process_action(event)
 end

 end

end

then I changed the initializer to this
assuming that if i pass both arg to an function and then do the logs it works, but i have still the same problem.

if LogStasher.enabled?

 LogStasher::ActiveSupport::LogSubscriber.class_eval do

 alias :original_process_action :process_action

 def process_action(event)
 hash = index: _id: event.payload[:request_id]
 do_logs(hash, event)
 end

 def do_logs(elastic_hash, original_log)
 # this creates the first line before each log
 log_extra_line = Logger.new("#Rails.root/log/logstasher.log")
 log_extra_line.info(elastic_hash.to_json) 
 # this adds the log line
 original_process_action(original_log)
 end

 end

end

What i am doing wrong?

This has to do with your server's concurrency. When run locally, by default Rails servers run a single thread. In production, they are usually multi-threaded. The log lines are coming in out-of-order because they belong to different requests.

Take a look at the rails docs on threading and concurrency for more info.

In the initializer, in the elastic_hash I added the event.
The new hash has first the index then the event.
Then i do

log = Logger.new("#Rails.root/log/logstasher.log")
log.info(elastic_hash.to_json)

with this i create only one line for each log, including index and event
and it works

In this case I wouldn't need the gem logsthasher i am sure that it would work different too