on_server_error callback executed within operations transaction

Beginne mit der bereitgestellten eigenständigen Ruby-Reproduktion, insbesondere mit ApplicationController#on_server_error und BugTest#test_unexpected_error, und führe sie mit dem gemeldeten Rails-Setup aus. Verfolge die Transaktion der create/update/destroy-Operation und den Zeitpunkt der Callbacks; abgeschlossen ist die Aufgabe, wenn die Fehlerbehandlung den ErrorLog-Datensatz persistieren kann, während die Ressourcenoperation zurückgerollt wird.

This issue is a (choose one):

• Problem/bug report.
• Feature request.
• Request for support. Note: Please try to avoid submitting issues for support requests. Use Gitter instead.

Checklist before submitting:

• I've searched for an existing issue.
• I've asked my question on Gitter and have not received a satisfactory answer.
• I've included a complete bug report template. This step helps us and allows us to see the bug without trying to reproduce the problem from your description. It helps you because you will frequently detect if it's a problem specific to your project.
• The feature I'm asking for is compliant with the JSON:API spec.

Description

When unexpected error appears during create/update/destroy of resource
on_server_error callback is executed within operations transaction
so any database update that was done will be rollbacked (for example we send error mail via active job)

Bug reports:

begin
  require 'bundler/inline'
  require 'bundler'
rescue LoadError => e
  STDERR.puts 'Bundler version 1.10 or later is required. Please update your Bundler'
  raise e
end

gemfile(true, ui: ENV['SILENT'] ? Bundler::UI::Silent.new : Bundler::UI::Shell.new) do
  source 'https://rubygems.org'

  gem 'rails', require: false

  if ENV['JSONAPI_RESOURCES_PG']
    gem 'pg'
  else
    gem 'sqlite3', '~> 1.3.6' # , platform: :mri
    # gem 'activerecord-jdbcsqlite3-adapter',
    #     git: 'https://github.com/jruby/activerecord-jdbc-adapter',
    #     branch: 'rails-5',
    #     platform: :jruby
  end


  if ENV['JSONAPI_RESOURCES_PATH']
    gem 'jsonapi-resources', path: ENV['JSONAPI_RESOURCES_PATH'], require: false
  elsif ENV['JSONAPI_RESOURCES_GEM']
    gem 'jsonapi-resources'
  else
    gem 'jsonapi-resources', git: 'https://github.com/cerebris/jsonapi-resources', require: false
  end

end

# prepare active_record database
require 'active_record'

class NullLogger < Logger
  def initialize(*_args)
  end

  def add(*_args, &_block)
  end
end

# establish database connection
if ENV['JSONAPI_RESOURCES_PG']
  db_name = 'tmp_bug_report_table'
  system("psql -c 'DROP DATABASE IF EXISTS #{db_name};'")
  system("psql -c 'CREATE DATABASE #{db_name};'")
  ActiveRecord::Base.establish_connection(adapter: 'postgresql', database: db_name)
else
  ActiveRecord::Base.establish_connection(adapter: 'sqlite3', database: ':memory:')
end

# specify logger
ActiveRecord::Base.logger = ENV['SILENT'] ? NullLogger.new : Logger.new(STDOUT)
ActiveRecord::Migration.verbose = !ENV['SILENT']

# define database schema
ActiveRecord::Schema.define do
  # Add your schema here
  create_table :users, force: true do |t|
    t.string :name
    t.integer :age
  end

  create_table :error_logs, force: true do |t|
    t.string :error_class, null: false
    t.string :error_message, null: false
    t.string :error_description, null: false
    t.json :extra_data, default: '{}', null: false
    t.timestamp :sent_at
    t.timestamps null: false
  end
end

# create models
class ApplicationRecord < ActiveRecord::Base
  self.abstract_class = true
end

class User < ApplicationRecord
  validates :name, presence: true
  validates :age, numericality: { greater_than_or_equal_to: 1 }

  attr_accessor :unexpected_failure

  before_save do
    if unexpected_failure
      raise StandardError, unexpected_failure.to_s
    end
  end
end

class ErrorLog < ApplicationRecord
  validates :error_class, :error_message, :error_description, presence: true

  class << self

    def from_exception(error, extra_data = {})
      new error_class: error.class.to_s,
          error_message: error.message,
          error_description: error_description_for(error),
          extra_data: extra_data
    end

    def error_description_for(error)
      bt = [error.backtrace.join("\n")]
      while error.cause && error.cause != error
        cause_bt = [
            'caused by:',
            error.cause.class.to_s,
            error.cause.message,
            error.cause.backtrace.join("\n")
        ].join("\n")
        bt.push cause_bt
        error = error.cause
      end
      bt.join("\n\n")
    end

  end
end

# prepare rails app
require 'action_controller/railtie'
# require 'action_view/railtie'
require 'jsonapi-resources'

class ApplicationController < ActionController::Base
  include JSONAPI::ActsAsResourceController

  on_server_error do |error|
    ErrorLog.from_exception(error).save!
  end
end

# prepare jsonapi resources and controllers
class UsersController < ApplicationController
  include JSONAPI::ActsAsResourceController
end

class UserResource < ::JSONAPI::Resource
  attributes :name, :age, :unexpected_failure
end

class TestApp < Rails::Application
  config.root = File.dirname(__FILE__)
  config.logger = ENV['SILENT'] ? NullLogger.new : Logger.new(STDOUT)
  Rails.logger = config.logger

  secrets.secret_token = 'secret_token'
  secrets.secret_key_base = 'secret_key_base'

  config.eager_load = false
end

# initialize app
Rails.application.initialize!

JSONAPI.configure do |config|
  config.json_key_format = :underscored_key
  config.route_format = :underscored_key
end

# draw routes
Rails.application.routes.draw do
  jsonapi_resources :users
end

# prepare tests
require 'minitest/autorun'
require 'rack/test'

# Replace this with the code necessary to make your test fail.
class BugTest < Minitest::Test
  include Rack::Test::Methods

  def teardown
    User.delete_all
    ErrorLog.delete_all
  end

  def test_success
    assert_equal 0, User.count
    assert_equal 0, ErrorLog.count

    post '/users', {
      data: {
          type: 'users',
          attributes: {
              name: 'John',
              age: 25
          }
      }
    }.to_json, json_api_headers

    assert_equal 201, last_response.status
    assert_equal 1, User.count
    assert_equal 0, ErrorLog.count
  end

  def test_unexpected_error
    assert_equal 0, User.count
    assert_equal 0, ErrorLog.count

    post '/users', {
        data: {
            type: 'users',
            attributes: {
                name: 'John',
                age: 25,
                unexpected_failure: 'some error'
            }
        }
    }.to_json, json_api_headers

    assert_equal 500, last_response.status
    assert_equal 0, User.count
    assert_equal 1, ErrorLog.count
  end

  private

  def json_api_headers
    {'Accept' => JSONAPI::MEDIA_TYPE, 'CONTENT_TYPE' => JSONAPI::MEDIA_TYPE}
  end

  def last_response_json
    JSON.parse(last_response.body).deep_symbolize_keys
  end

  def app
    Rails.application
  end
end

execution log

$ JSONAPI_RESOURCES_PATH="/home/senid/projects/forked/jsonapi-resources" RAILS_VERSION="~> 5.2.2" ruby custom_bug_report_local_server_error_rollback.rb

Fetching gem metadata from https://rubygems.org/.............
Fetching gem metadata from https://rubygems.org/.
Resolving dependencies...
Using rake 12.3.2
Using concurrent-ruby 1.1.4
Using i18n 1.6.0
Using minitest 5.11.3
Using thread_safe 0.3.6
Using tzinfo 1.2.5
Using activesupport 5.2.2
Using builder 3.2.3
Using erubi 1.8.0
Using mini_portile2 2.4.0
Using nokogiri 1.10.1
Using rails-dom-testing 2.0.3
Using crass 1.0.4
Using loofah 2.2.3
Using rails-html-sanitizer 1.0.4
Using actionview 5.2.2
Using rack 2.0.6
Using rack-test 1.1.0
Using actionpack 5.2.2
Using nio4r 2.3.1
Using websocket-extensions 0.1.3
Using websocket-driver 0.7.0
Using actioncable 5.2.2
Using globalid 0.4.2
Using activejob 5.2.2
Using mini_mime 1.0.1
Using mail 2.7.1
Using actionmailer 5.2.2
Using activemodel 5.2.2
Using arel 9.0.0
Using activerecord 5.2.2
Using mimemagic 0.3.3
Using marcel 0.3.3
Using activestorage 5.2.2
Using bundler 2.0.1
Using method_source 0.9.2
Using thor 0.20.3
Using railties 5.2.2
Using jsonapi-resources 0.9.5 from source at `/home/senid/projects/forked/jsonapi-resources`
Using sprockets 3.7.2
Using sprockets-rails 3.2.1
Using rails 5.2.2
Using sqlite3 1.3.13
-- create_table(:users, {:force=>true})
D, [2019-03-05T15:13:02.774311 #32574] DEBUG -- :    (0.1ms)  DROP TABLE IF EXISTS "users"
D, [2019-03-05T15:13:02.775610 #32574] DEBUG -- :    (0.6ms)  SELECT sqlite_version(*)
D, [2019-03-05T15:13:02.775950 #32574] DEBUG -- :    (0.2ms)  CREATE TABLE "users" ("id" integer PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "age" integer)
   -> 0.0040s
-- create_table(:error_logs, {:force=>true})
D, [2019-03-05T15:13:02.776319 #32574] DEBUG -- :    (0.1ms)  DROP TABLE IF EXISTS "error_logs"
D, [2019-03-05T15:13:02.776835 #32574] DEBUG -- :    (0.1ms)  CREATE TABLE "error_logs" ("id" integer PRIMARY KEY AUTOINCREMENT NOT NULL, "error_class" varchar NOT NULL, "error_message" varchar NOT NULL, "error_description" varchar NOT NULL, "extra_data" json DEFAULT '"{}"' NOT NULL, "sent_at" datetime, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
   -> 0.0008s
D, [2019-03-05T15:13:02.799279 #32574] DEBUG -- :    (0.2ms)  CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2019-03-05T15:13:02.810540 #32574] DEBUG -- :   ActiveRecord::InternalMetadata Load (0.3ms)  SELECT  "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ?  [["key", "environment"], ["LIMIT", 1]]
D, [2019-03-05T15:13:02.815675 #32574] DEBUG -- :    (0.1ms)  begin transaction
D, [2019-03-05T15:13:02.816866 #32574] DEBUG -- :   ActiveRecord::InternalMetadata Create (0.1ms)  INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?)  [["key", "environment"], ["value", "default_env"], ["created_at", "2019-03-05 13:13:02.816198"], ["updated_at", "2019-03-05 13:13:02.816198"]]
D, [2019-03-05T15:13:02.817085 #32574] DEBUG -- :    (0.0ms)  commit transaction
Run options: --seed 62801

# Running:

D, [2019-03-05T15:13:03.200841 #32574] DEBUG -- :    (0.1ms)  SELECT COUNT(*) FROM "users"
D, [2019-03-05T15:13:03.201957 #32574] DEBUG -- :    (0.1ms)  SELECT COUNT(*) FROM "error_logs"
I, [2019-03-05T15:13:03.209005 #32574]  INFO -- : Started POST "/users" for 127.0.0.1 at 2019-03-05 15:13:03 +0200
I, [2019-03-05T15:13:03.211044 #32574]  INFO -- : Processing by UsersController#create as HTML
I, [2019-03-05T15:13:03.211106 #32574]  INFO -- :   Parameters: {"data"=>{"type"=>"users", "attributes"=>{"name"=>"John", "age"=>25}}}
D, [2019-03-05T15:13:03.212028 #32574] DEBUG -- :    (0.1ms)  begin transaction
D, [2019-03-05T15:13:03.215715 #32574] DEBUG -- :   User Create (0.1ms)  INSERT INTO "users" ("name", "age") VALUES (?, ?)  [["name", "John"], ["age", 25]]
D, [2019-03-05T15:13:03.215973 #32574] DEBUG -- :    (0.1ms)  commit transaction
I, [2019-03-05T15:13:03.218233 #32574]  INFO -- :   Rendering text template
I, [2019-03-05T15:13:03.218320 #32574]  INFO -- :   Rendered text template (0.0ms)
I, [2019-03-05T15:13:03.218449 #32574]  INFO -- : Completed 201 Created in 7ms (Views: 1.7ms)


D, [2019-03-05T15:13:03.219316 #32574] DEBUG -- :    (0.1ms)  SELECT COUNT(*) FROM "users"
D, [2019-03-05T15:13:03.219659 #32574] DEBUG -- :    (0.1ms)  SELECT COUNT(*) FROM "error_logs"
D, [2019-03-05T15:13:03.219980 #32574] DEBUG -- :   User Destroy (0.1ms)  DELETE FROM "users"
D, [2019-03-05T15:13:03.220199 #32574] DEBUG -- :   ErrorLog Destroy (0.0ms)  DELETE FROM "error_logs"
.D, [2019-03-05T15:13:03.220566 #32574] DEBUG -- :    (0.1ms)  SELECT COUNT(*) FROM "users"
D, [2019-03-05T15:13:03.220861 #32574] DEBUG -- :    (0.1ms)  SELECT COUNT(*) FROM "error_logs"
I, [2019-03-05T15:13:03.221399 #32574]  INFO -- : Started POST "/users" for 127.0.0.1 at 2019-03-05 15:13:03 +0200
I, [2019-03-05T15:13:03.222103 #32574]  INFO -- : Processing by UsersController#create as HTML
I, [2019-03-05T15:13:03.222164 #32574]  INFO -- :   Parameters: {"data"=>{"type"=>"users", "attributes"=>{"name"=>"John", "age"=>25, "unexpected_failure"=>"some error"}}}
D, [2019-03-05T15:13:03.222950 #32574] DEBUG -- :    (0.1ms)  begin transaction
D, [2019-03-05T15:13:03.230776 #32574] DEBUG -- :   ErrorLog Create (0.2ms)  INSERT INTO "error_logs" ("error_class", "error_message", "error_description", "extra_data", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?, ?)  [["error_class", "StandardError"], ["error_message", "some error"], ["error_description", "custom_bug_report_local_server_error_rollback.rb:91:in `block in <class:User>'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:426:in `instance_exec'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:426:in `block in make_lambda'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:198:in `block (2 levels) in halting'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:606:in `block (2 levels) in default_terminator'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:605:in `catch'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:605:in `block in default_terminator'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:199:in `block in halting'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:513:in `block in invoke_before'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:513:in `each'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:513:in `invoke_before'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:131:in `run_callbacks'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:816:in `_run_save_callbacks'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/callbacks.rb:342:in `create_or_update'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/persistence.rb:273:in `save'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/validations.rb:46:in `save'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:310:in `block (2 levels) in save'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/database_statements.rb:257:in `transaction'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:212:in `transaction'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:385:in `with_transaction_returning_status'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:310:in `block in save'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:325:in `rollback_active_record_state!'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:309:in `save'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/suppressor.rb:44:in `save'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:204:in `_save'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:181:in `block in save'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:180:in `save'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:61:in `block in change'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:55:in `change'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:111:in `replace_fields'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/processor.rb:233:in `create_resource'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/processor.rb:58:in `block (2 levels) in process'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/processor.rb:57:in `block in process'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/processor.rb:56:in `process'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation.rb:16:in `process'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:58:in `block in process_operation'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:63:in `with_default_handling'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:57:in `process_operation'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:29:in `block (2 levels) in process'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:28:in `each'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:28:in `block in process'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:43:in `block in transaction'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:93:in `block (2 levels) in transaction'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/database_statements.rb:259:in `block in transaction'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/transaction.rb:239:in `block in within_new_transaction'\n/home/senid/.rvm/rubies/ruby-2.3.8-railsexpress/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/transaction.rb:236:in `within_new_transaction'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/database_statements.rb:259:in `transaction'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:212:in `transaction'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:92:in `block in transaction'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:42:in `transaction'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:24:in `process'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:86:in `block in process_operations'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:85:in `process_operations'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:77:in `process_request'\n/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:29:in `create'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/abstract_controller/base.rb:194:in `process_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/rendering.rb:30:in `process_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/abstract_controller/callbacks.rb:42:in `block in process_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/abstract_controller/callbacks.rb:41:in `process_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/rescue.rb:22:in `process_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `block in instrument'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/notifications/instrumenter.rb:23:in `instrument'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `instrument'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:32:in `process_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/abstract_controller/base.rb:134:in `process'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionview-5.2.2/lib/action_view/rendering.rb:32:in `process'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal.rb:191:in `dispatch'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal.rb:252:in `dispatch'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:34:in `serve'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:52:in `block in serve'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:35:in `each'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:35:in `serve'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:840:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/tempfile_reaper.rb:15:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/etag.rb:25:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/conditional_get.rb:38:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/head.rb:12:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/http/content_security_policy.rb:18:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/session/abstract/id.rb:232:in `context'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/session/abstract/id.rb:226:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/cookies.rb:670:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/callbacks.rb:26:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/executor.rb:14:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/railties-5.2.2/lib/rails/rack/logger.rb:38:in `call_app'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/railties-5.2.2/lib/rails/rack/logger.rb:28:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/request_id.rb:27:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/method_override.rb:22:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/runtime.rb:22:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/executor.rb:14:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/static.rb:127:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/sendfile.rb:111:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/railties-5.2.2/lib/rails/engine.rb:524:in `call'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-test-1.1.0/lib/rack/mock_session.rb:29:in `request'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-test-1.1.0/lib/rack/test.rb:266:in `process_request'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-test-1.1.0/lib/rack/test.rb:129:in `custom_request'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-test-1.1.0/lib/rack/test.rb:66:in `post'\n/home/senid/.rvm/rubies/ruby-2.3.8-railsexpress/lib/ruby/2.3.0/forwardable.rb:202:in `post'\ncustom_bug_report_local_server_error_rollback.rb:208:in `test_unexpected_error'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:98:in `block (3 levels) in run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:195:in `capture_exceptions'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:95:in `block (2 levels) in run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:265:in `time_it'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:94:in `block in run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:211:in `with_info_handler'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:93:in `run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:960:in `run_one_method'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:334:in `run_one_method'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:321:in `block (2 levels) in run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:320:in `each'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:320:in `block in run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:347:in `with_info_handler'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:319:in `run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:159:in `block in __run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:159:in `map'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:159:in `__run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:136:in `run'\n/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:63:in `block in autorun'"], ["extra_data", "{}"], ["created_at", "2019-03-05 13:13:03.229773"], ["updated_at", "2019-03-05 13:13:03.229773"]]
E, [2019-03-05T15:13:03.232004 #32574] ERROR -- : Internal Server Error: some error custom_bug_report_local_server_error_rollback.rb:91:in `block in <class:User>'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:426:in `instance_exec'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:426:in `block in make_lambda'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:198:in `block (2 levels) in halting'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:606:in `block (2 levels) in default_terminator'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:605:in `catch'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:605:in `block in default_terminator'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:199:in `block in halting'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:513:in `block in invoke_before'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:513:in `each'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:513:in `invoke_before'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:131:in `run_callbacks'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:816:in `_run_save_callbacks'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/callbacks.rb:342:in `create_or_update'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/persistence.rb:273:in `save'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/validations.rb:46:in `save'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:310:in `block (2 levels) in save'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/database_statements.rb:257:in `transaction'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:212:in `transaction'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:385:in `with_transaction_returning_status'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:310:in `block in save'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:325:in `rollback_active_record_state!'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:309:in `save'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/suppressor.rb:44:in `save'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:204:in `_save'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:181:in `block in save'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:180:in `save'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:61:in `block in change'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:55:in `change'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/resource.rb:111:in `replace_fields'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/processor.rb:233:in `create_resource'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/processor.rb:58:in `block (2 levels) in process'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/processor.rb:57:in `block in process'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/processor.rb:56:in `process'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation.rb:16:in `process'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:58:in `block in process_operation'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:63:in `with_default_handling'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:57:in `process_operation'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:29:in `block (2 levels) in process'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:28:in `each'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:28:in `block in process'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:43:in `block in transaction'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:93:in `block (2 levels) in transaction'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/database_statements.rb:259:in `block in transaction'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/transaction.rb:239:in `block in within_new_transaction'
/home/senid/.rvm/rubies/ruby-2.3.8-railsexpress/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/transaction.rb:236:in `within_new_transaction'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/connection_adapters/abstract/database_statements.rb:259:in `transaction'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activerecord-5.2.2/lib/active_record/transactions.rb:212:in `transaction'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:92:in `block in transaction'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:42:in `transaction'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/operation_dispatcher.rb:24:in `process'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:86:in `block in process_operations'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:85:in `process_operations'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:77:in `process_request'
/home/senid/projects/forked/jsonapi-resources/lib/jsonapi/acts_as_resource_controller.rb:29:in `create'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/abstract_controller/base.rb:194:in `process_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/rendering.rb:30:in `process_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/abstract_controller/callbacks.rb:41:in `process_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/rescue.rb:22:in `process_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `block in instrument'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `instrument'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/abstract_controller/base.rb:134:in `process'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionview-5.2.2/lib/action_view/rendering.rb:32:in `process'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal.rb:191:in `dispatch'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_controller/metal.rb:252:in `dispatch'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:34:in `serve'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:52:in `block in serve'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:35:in `each'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:35:in `serve'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:840:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/tempfile_reaper.rb:15:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/etag.rb:25:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/conditional_get.rb:38:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/head.rb:12:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/session/abstract/id.rb:232:in `context'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/session/abstract/id.rb:226:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/cookies.rb:670:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/executor.rb:14:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/railties-5.2.2/lib/rails/rack/logger.rb:38:in `call_app'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/railties-5.2.2/lib/rails/rack/logger.rb:28:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/method_override.rb:22:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/runtime.rb:22:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/activesupport-5.2.2/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/executor.rb:14:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/actionpack-5.2.2/lib/action_dispatch/middleware/static.rb:127:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-2.0.6/lib/rack/sendfile.rb:111:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/railties-5.2.2/lib/rails/engine.rb:524:in `call'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-test-1.1.0/lib/rack/mock_session.rb:29:in `request'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-test-1.1.0/lib/rack/test.rb:266:in `process_request'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-test-1.1.0/lib/rack/test.rb:129:in `custom_request'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/rack-test-1.1.0/lib/rack/test.rb:66:in `post'
/home/senid/.rvm/rubies/ruby-2.3.8-railsexpress/lib/ruby/2.3.0/forwardable.rb:202:in `post'
custom_bug_report_local_server_error_rollback.rb:208:in `test_unexpected_error'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:98:in `block (3 levels) in run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:195:in `capture_exceptions'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:95:in `block (2 levels) in run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:265:in `time_it'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:94:in `block in run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:211:in `with_info_handler'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest/test.rb:93:in `run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:960:in `run_one_method'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:334:in `run_one_method'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:321:in `block (2 levels) in run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:320:in `each'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:320:in `block in run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:347:in `with_info_handler'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:319:in `run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:159:in `block in __run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:159:in `map'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:159:in `__run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:136:in `run'
/home/senid/.rvm/gems/ruby-2.3.8-railsexpress@jsonapi-resources_bug-report-template/gems/minitest-5.11.3/lib/minitest.rb:63:in `block in autorun'
D, [2019-03-05T15:13:03.235828 #32574] DEBUG -- :    (0.1ms)  rollback transaction
I, [2019-03-05T15:13:03.237496 #32574]  INFO -- : Completed 500 Internal Server Error in 15ms (Views: 1.4ms)


D, [2019-03-05T15:13:03.238231 #32574] DEBUG -- :    (0.1ms)  SELECT COUNT(*) FROM "users"
D, [2019-03-05T15:13:03.238568 #32574] DEBUG -- :    (0.1ms)  SELECT COUNT(*) FROM "error_logs"
D, [2019-03-05T15:13:03.238920 #32574] DEBUG -- :   User Destroy (0.1ms)  DELETE FROM "users"
D, [2019-03-05T15:13:03.239139 #32574] DEBUG -- :   ErrorLog Destroy (0.1ms)  DELETE FROM "error_logs"
F

Failure:
BugTest#test_unexpected_error [custom_bug_report_local_server_error_rollback.rb:221]:
Expected: 1
  Actual: 0


bin/rails test custom_bug_report_local_server_error_rollback.rb:204



Finished in 0.040997s, 48.7838 runs/s, 243.9190 assertions/s.
2 runs, 10 assertions, 1 failures, 0 errors, 0 skips