Unable to access LDAP in integrations StatusCode 500

s_woods666 · August 16, 2018, 1:52pm

Used Zammad version: 2.6.x
Used Zammad installation source: APT repo
Operating system: Ubuntu 16.04.5 LTS
Browser + version: Chrome Version 68.0.3440.106 (Official Build) (64-bit)

Expected behaviour:

I have configured the LDAP integration and was attempting to sync the agents to specific groups

Actual behaviour:

As soon as you select the integrations tabs an error window pops up showing

StatusCode:500
the message under this reads.

{“error”:""\xE2" from ASCII-8BIT to UTF-8"}

the same error pops up if you attempt to select any of the following tabs.
Tags, Time accounting, Web, Form, Email, Branding, Maintenance. Plus some more.

Steps to reproduce the behavior:

I synced some of the agent details. They are in an active directory OU group to be added and there is an additional OU group for the Admin users.

This is a fresh install of Zammad but not a fresh ubuntu install. I have been working my way through the different areas of the system to fully test it but this has popped up.

Thanks for any guidance.

Simon

MrGeneration · August 16, 2018, 2:15pm

This looks like it’s this bug:

flies away

s_woods666 · August 16, 2018, 3:00pm

Thank you for the help, I had searched but did not see this. I have checked and found the same error is in the production.log. I have reset the ldap and can now get the to integrations tab. I will backup the server and retry.

Thanks

MrGeneration · August 16, 2018, 3:10pm

You’re welcome, please feel free to give us Feedback, if the patch did fix your problem.

s_woods666 · August 16, 2018, 3:16pm

I applied the modified user.rb file and that has helped.

The system did still show the same error but I can now access the ldap tab without the error.
It looks like some of the agents have been imported but some are missing. I will investigate further tomorrow.

Thanks

s_woods666 · August 17, 2018, 12:28pm

Hi, feedback as suggested.

I have tested this further today. The modified user.rb file does make the menu available. I mistakenly updated the server which included Zammad and undid the modified user.rb file. I reset Ldap and created a new sync and the same error popped up again. I then redid the user.rb file and the menus appeared again.

Again thanks for the assistance.

MrGeneration · August 17, 2018, 1:35pm

Hey sorry for asking, but I don’t see a question here.
Is this just an information for us?

s_woods666 · August 17, 2018, 1:38pm

Hi,

Yep just feedback on the modified user.rb file.

Thanks

MrGeneration · August 17, 2018, 1:39pm

Okay great, awesome - thank you very much.

MamoulianDelacroix · August 20, 2018, 9:22am

@s_woods666: I have a stupide question
How did you reset your ldap settings?
I have the same problem in our zammad-system and I’m stucked at this point.

s_woods666 · August 20, 2018, 9:37am

Hi,

I was able to ssh on to the server and then run the following command from the /opt/zammad folder.

$ RAILS_ENV=production zammad run rails r "Setting.set('ldap_config', {})"

I then restarted zammad.

Thanks

MamoulianDelacroix · August 20, 2018, 10:10am

@s_woods666: Thank you very much.
In the meantime I found a way to do that via postgres. I deleted the relevant informations in the settings table.
In my case there was an alternative workaround. I just disabled the ldap integration via postgres.

MamoulianDelacroix · August 20, 2018, 10:15am

Ok nevermind, after I updated zammad to the current version, simply disable the ldap integration didn’t help anymore.

s_woods666 · August 20, 2018, 10:22am

Hi,

I did the same and updated zammad, this caused mine to error again. There is a modified user.rb file that helps but is replaced during the update process so needed to be redone.

Possibly worth a read through the post suggested by MrGenerations above. This has the links to the modified file and where it goes. This helped me.

Good luck

Thanks

MamoulianDelacroix · August 20, 2018, 12:04pm

that custome user.rb works like a charm

thorsteneckel · August 20, 2018, 3:23pm

Could you please both post your log/production.log file - or at least the error entry (with traceback).

@MamoulianDelacroix - please never remove/alter data in the DB directly. This will most likely lead to errors or at least unexpected behavior.

MamoulianDelacroix · August 21, 2018, 6:49am

good to know, thank you
I hope this helps:

I, [2018-08-20T12:11:23.758828 #8851]  INFO -- : Completed 500 Internal Server Error in 332ms (Views: 0.1ms | ActiveRecord: 9.5ms)
I, [2018-08-20T12:11:25.034172 #8851]  INFO -- : Started PUT "/api/v1/taskbar/4642" for 127.0.0.1 at 2018-08-20 12:11:25 +0200
I, [2018-08-20T12:11:25.038869 #8851]  INFO -- : Processing by TaskbarController#update as JSON
I, [2018-08-20T12:11:25.038950 #8851]  INFO -- :   Parameters: {"key"=>"Ticket-873", "client_id"=>"123", "callback"=>"TicketZoom", "state"=>{"ticket"=>{}, "article"=>{"form_id"=>"758856434"}}, "params"=>{"ticket_id"=>"873", "article_id"=>"3458", "init"=>true}, "prio"=>5, "notify"=>false, "active"=>false, "attachments"=>[], "updated_at"=>"2018-08-20T10:05:58.727Z", "id"=>"4642"}
I, [2018-08-20T12:11:25.084940 #8851]  INFO -- : Completed 200 OK in 46ms (Views: 0.3ms | ActiveRecord: 4.6ms)
I, [2018-08-20T12:11:25.104348 #8851]  INFO -- : Started PUT "/api/v1/taskbar/4637" for 127.0.0.1 at 2018-08-20 12:11:25 +0200
I, [2018-08-20T12:11:25.107517 #8851]  INFO -- : Processing by TaskbarController#update as JSON
I, [2018-08-20T12:11:25.107577 #8851]  INFO -- :   Parameters: {"key"=>"Ticket-672", "client_id"=>"123", "callback"=>"TicketZoom", "state"=>{"ticket"=>{}, "article"=>{"form_id"=>"746033089"}}, "params"=>{"ticket_id"=>"672", "init"=>true}, "prio"=>3, "notify"=>false, "active"=>false, "attachments"=>[], "updated_at"=>"2018-08-20T07:12:37.317Z", "id"=>"4637"}
I, [2018-08-20T12:11:25.138308 #8851]  INFO -- : Completed 200 OK in 31ms (Views: 0.3ms | ActiveRecord: 3.0ms)
I, [2018-08-20T12:11:25.154461 #8851]  INFO -- : Started PUT "/api/v1/taskbar/4638" for 127.0.0.1 at 2018-08-20 12:11:25 +0200
I, [2018-08-20T12:11:25.157408 #8851]  INFO -- : Processing by TaskbarController#update as JSON
I, [2018-08-20T12:11:25.157464 #8851]  INFO -- :   Parameters: {"key"=>"Ticket-410", "client_id"=>"123", "callback"=>"TicketZoom", "state"=>{"ticket"=>{}, "article"=>{"form_id"=>"745992189"}}, "params"=>{"ticket_id"=>"410", "init"=>true}, "prio"=>4, "notify"=>false, "active"=>false, "attachments"=>[], "updated_at"=>"2018-08-20T07:12:37.481Z", "id"=>"4638"}
I, [2018-08-20T12:11:25.173764 #8851]  INFO -- : Completed 200 OK in 16ms (Views: 0.3ms | ActiveRecord: 2.4ms)
I, [2018-08-20T12:11:25.195873 #8851]  INFO -- : Started PUT "/api/v1/taskbar/4636" for 127.0.0.1 at 2018-08-20 12:11:25 +0200
I, [2018-08-20T12:11:25.198816 #8851]  INFO -- : Processing by TaskbarController#update as JSON
I, [2018-08-20T12:11:25.198872 #8851]  INFO -- :   Parameters: {"key"=>"Ticket-909", "client_id"=>"123", "callback"=>"TicketZoom", "state"=>{"ticket"=>{}, "article"=>{"form_id"=>"745920864"}}, "params"=>{"ticket_id"=>"909", "init"=>true}, "prio"=>2, "notify"=>false, "active"=>false, "attachments"=>[], "updated_at"=>"2018-08-20T09:04:07.119Z", "id"=>"4636"}
I, [2018-08-20T12:11:25.223487 #8851]  INFO -- : Completed 200 OK in 25ms (Views: 0.4ms | ActiveRecord: 2.8ms)
I, [2018-08-20T12:11:27.999384 #8851]  INFO -- : Started GET "/api/v1/monitoring/health_check?token=McGw9aYQdJenCDKwcwCSGK43ouag_ysYEexQP43s5u780xVctUgHkw" for 193.29.186.168 at 2018-08-20 12:11:27 +0200
I, [2018-08-20T12:11:28.001655 #8851]  INFO -- : Processing by MonitoringController#health_check as */*
I, [2018-08-20T12:11:28.001695 #8851]  INFO -- :   Parameters: {"token"=>"McGw9aYQdJenCDKwcwCSGK43ouag_ysYEexQP43s5u780xVctUgHkw"}
I, [2018-08-20T12:11:28.014101 #8851]  INFO -- : Completed 200 OK in 12ms (Views: 0.2ms | ActiveRecord: 5.0ms)
I, [2018-08-20T12:11:28.376812 #8851]  INFO -- : Started GET "/api/v1/settings/?full=true&_=1534759899300" for 127.0.0.1 at 2018-08-20 12:11:28 +0200
I, [2018-08-20T12:11:28.380621 #8851]  INFO -- : Processing by SettingsController#index as JSON
I, [2018-08-20T12:11:28.380669 #8851]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534759899300"}
E, [2018-08-20T12:11:28.663537 #8851] ERROR -- : "\xC2" from ASCII-8BIT to UTF-8 (Encoding::UndefinedConversionError)
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:55:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/json-2.1.0/lib/json/common.rb:224:in `generate'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/json-2.1.0/lib/json/common.rb:224:in `generate'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:100:in `stringify'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:33:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:20:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:39:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:156:in `block in <module:Renderers>'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:149:in `block in _render_to_body_with_renderer'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/set.rb:324:in `each_key'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/set.rb:324:in `each'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:145:in `_render_to_body_with_renderer'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:141:in `render_to_body'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/rendering.rb:24:in `render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rendering.rb:36:in `render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/benchmark.rb:12:in `block in ms'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/benchmark.rb:308:in `realtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/benchmark.rb:12:in `ms'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:44:in `block in render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:87:in `cleanup_view_runtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.5/lib/active_record/railties/controller_runtime.rb:29:in `cleanup_view_runtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:43:in `render'
/opt/zammad/app/controllers/settings_controller.rb:13:in `index'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/base.rb:186:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rendering.rb:30:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/callbacks.rb:131:in `run_callbacks'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/callbacks.rb:19:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rescue.rb:20:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/notifications.rb:166:in `block in instrument'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/notifications.rb:166:in `instrument'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/params_wrapper.rb:252:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.5/lib/active_record/railties/controller_runtime.rb:22:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/base.rb:124:in `process'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionview-5.1.5/lib/action_view/rendering.rb:30:in `process'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal.rb:189:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal.rb:253:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/routing/route_set.rb:31:in `serve'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/journey/router.rb:50:in `block in serve'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/journey/router.rb:33:in `each'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/journey/router.rb:33:in `serve'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/routing/route_set.rb:844:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/builder.rb:63:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/etag.rb:25:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/conditional_get.rb:25:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in `context'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/cookies.rb:613:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/callbacks.rb:26:in `block in call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/callbacks.rb:97:in `run_callbacks'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/callbacks.rb:24:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/railties-5.1.5/lib/rails/rack/logger.rb:36:in `call_app'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/railties-5.1.5/lib/rails/rack/logger.rb:24:in `block in call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/tagged_logging.rb:69:in `block in tagged'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/tagged_logging.rb:26:in `tagged'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/tagged_logging.rb:69:in `tagged'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/railties-5.1.5/lib/rails/rack/logger.rb:24:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/request_id.rb:25:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/runtime.rb:22:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/executor.rb:12:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/railties-5.1.5/lib/rails/engine.rb:522:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/configuration.rb:225:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:624:in `handle_request'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:438:in `process_client'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:302:in `block in run'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/thread_pool.rb:120:in `block in spawn_thread'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
I, [2018-08-20T12:11:28.664002 #8851]  INFO -- : Completed 500 Internal Server Error in 283ms (Views: 0.1ms | ActiveRecord: 9.8ms)
I, [2018-08-20T12:11:32.066704 #8851]  INFO -- : Started GET "/api/v1/settings/?full=true&_=1534759899301" for 127.0.0.1 at 2018-08-20 12:11:32 +0200
I, [2018-08-20T12:11:32.070150 #8851]  INFO -- : Processing by SettingsController#index as JSON
I, [2018-08-20T12:11:32.070200 #8851]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534759899301"}
E, [2018-08-20T12:11:32.357818 #8851] ERROR -- : "\xC2" from ASCII-8BIT to UTF-8 (Encoding::UndefinedConversionError)
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:55:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/json-2.1.0/lib/json/common.rb:224:in `generate'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/json-2.1.0/lib/json/common.rb:224:in `generate'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:100:in `stringify'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:33:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:20:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:39:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:156:in `block in <module:Renderers>'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:149:in `block in _render_to_body_with_renderer'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/set.rb:324:in `each_key'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/set.rb:324:in `each'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:145:in `_render_to_body_with_renderer'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:141:in `render_to_body'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/rendering.rb:24:in `render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rendering.rb:36:in `render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/benchmark.rb:12:in `block in ms'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/benchmark.rb:308:in `realtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/benchmark.rb:12:in `ms'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:44:in `block in render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:87:in `cleanup_view_runtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.5/lib/active_record/railties/controller_runtime.rb:29:in `cleanup_view_runtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:43:in `render'
/opt/zammad/app/controllers/settings_controller.rb:13:in `index'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/base.rb:186:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rendering.rb:30:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/callbacks.rb:131:in `run_callbacks'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/callbacks.rb:19:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rescue.rb:20:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/notifications.rb:166:in `block in instrument'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/notifications.rb:166:in `instrument'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/params_wrapper.rb:252:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.5/lib/active_record/railties/controller_runtime.rb:22:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/base.rb:124:in `process'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionview-5.1.5/lib/action_view/rendering.rb:30:in `process'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal.rb:189:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal.rb:253:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/routing/route_set.rb:31:in `serve'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/journey/router.rb:50:in `block in serve'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/journey/router.rb:33:in `each'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/journey/router.rb:33:in `serve'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/routing/route_set.rb:844:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:190:in `call!'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/strategy.rb:168:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/omniauth-1.7.1/lib/omniauth/builder.rb:63:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/etag.rb:25:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/conditional_get.rb:25:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/head.rb:12:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in `context'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/cookies.rb:613:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/callbacks.rb:26:in `block in call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/callbacks.rb:97:in `run_callbacks'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/callbacks.rb:24:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/railties-5.1.5/lib/rails/rack/logger.rb:36:in `call_app'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/railties-5.1.5/lib/rails/rack/logger.rb:24:in `block in call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/tagged_logging.rb:69:in `block in tagged'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/tagged_logging.rb:26:in `tagged'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/tagged_logging.rb:69:in `tagged'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/railties-5.1.5/lib/rails/rack/logger.rb:24:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/request_id.rb:25:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/method_override.rb:22:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/runtime.rb:22:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/executor.rb:12:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/railties-5.1.5/lib/rails/engine.rb:522:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/configuration.rb:225:in `call'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:624:in `handle_request'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:438:in `process_client'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:302:in `block in run'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/thread_pool.rb:120:in `block in spawn_thread'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
I, [2018-08-20T12:11:32.358255 #8851]  INFO -- : Completed 500 Internal Server Error in 288ms (Views: 0.1ms | ActiveRecord: 13.4ms)
I, [2018-08-20T12:11:33.932989 #8851]  INFO -- : Started GET "/api/v1/object_manager_attributes_list?_=1534759899302" for 127.0.0.1 at 2018-08-20 12:11:33 +0200
I, [2018-08-20T12:11:33.938494 #8851]  INFO -- : Processing by ObjectManagerAttributesController#list as JSON
I, [2018-08-20T12:11:33.938558 #8851]  INFO -- :   Parameters: {"_"=>"1534759899302"}
I, [2018-08-20T12:11:33.945874 #8851]  INFO -- : Completed 200 OK in 7ms (Views: 0.2ms | ActiveRecord: 1.6ms)
I, [2018-08-20T12:11:33.999290 #8851]  INFO -- : Started GET "/api/v1/object_manager_attributes" for 127.0.0.1 at 2018-08-20 12:11:33 +0200
I, [2018-08-20T12:11:34.003015 #8851]  INFO -- : Processing by ObjectManagerAttributesController#index as JSON
I, [2018-08-20T12:11:34.005048 #8851]  INFO -- : Started GET "/api/v1/object_manager_attributes" for 127.0.0.1 at 2018-08-20 12:11:34 +0200
I, [2018-08-20T12:11:34.008814 #8851]  INFO -- : Processing by ObjectManagerAttributesController#index as JSON
I, [2018-08-20T12:11:34.014025 #8851]  INFO -- : Started GET "/api/v1/object_manager_attributes" for 127.0.0.1 at 2018-08-20 12:11:34 +0200
I, [2018-08-20T12:11:34.018259 #8851]  INFO -- : Processing by ObjectManagerAttributesController#index as JSON
I, [2018-08-20T12:11:34.025940 #8851]  INFO -- : Started GET "/api/v1/object_manager_attributes" for 127.0.0.1 at 2018-08-20 12:11:34 +0200
I, [2018-08-20T12:11:34.034434 #8851]  INFO -- : Processing by ObjectManagerAttributesController#index as JSON
I, [2018-08-20T12:11:34.143843 #8851]  INFO -- : Completed 200 OK in 135ms (Views: 7.0ms | ActiveRecord: 69.1ms)
I, [2018-08-20T12:11:34.198064 #8851]  INFO -- : Completed 200 OK in 180ms (Views: 7.0ms | ActiveRecord: 61.7ms)
I, [2018-08-20T12:11:34.198347 #8851]  INFO -- : Completed 200 OK in 195ms (Views: 19.4ms | ActiveRecord: 66.3ms)
I, [2018-08-20T12:11:34.305311 #8851]  INFO -- : Completed 200 OK in 258ms (Views: 63.4ms | ActiveRecord: 92.6ms)
I, [2018-08-20T12:11:36.156350 #8851]  INFO -- : Started GET "/api/v1/settings/?full=true&_=1534759899303" for 127.0.0.1 at 2018-08-20 12:11:36 +0200
I, [2018-08-20T12:11:36.160774 #8851]  INFO -- : Processing by SettingsController#index as JSON
I, [2018-08-20T12:11:36.160898 #8851]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534759899303"}
E, [2018-08-20T12:11:36.446872 #8851] ERROR -- : "\xC2" from ASCII-8BIT to UTF-8 (Encoding::UndefinedConversionError)
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:55:in `to_json'

thorsteneckel · August 21, 2018, 8:03am

Thanks @MamoulianDelacroix! This is actually the bug for which we’re currently working on a fix. However, writing a test is harder than expected (mocking LDAP connections and stuff) - but we’ll get there. Glad to hear that the actual bugfix already works for you.

MamoulianDelacroix · August 21, 2018, 9:42am

Sadly, somehow the bugfix doesn’t work anymore
For testing purpose I logged out of zammad and startet a new zammad session within a private tab.
And the error reappears.
I just reapplied the hotfix and tried it again.
Here is my current production.log:

I, [2018-08-21T10:23:25.504597 #28721]  INFO -- : # curl -X POST "http://127.0.0.1:9200/itszammad01_zammad_production/User/268?pipeline=zammad653674631327" \
I, [2018-08-21T10:23:25.509039 #28721]  INFO -- : # 200
I, [2018-08-21T10:23:25.516960 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job BackgroundJobSearchIndex (id=3495356) COMPLETED after 0.0312
I, [2018-08-21T10:23:25.518640 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job BackgroundJobSearchIndex (id=3495357) RUNNING
I, [2018-08-21T10:23:25.529897 #28717]  INFO -- : Completed 200 OK in 147ms (Views: 6.0ms | ActiveRecord: 1.9ms)
I, [2018-08-21T10:23:25.536643 #28721]  INFO -- : # curl -X POST "http://127.0.0.1:9200/itszammad01_zammad_production/User/78?pipeline=zammad653674631327" \
I, [2018-08-21T10:23:25.540841 #28721]  INFO -- : # 200
I, [2018-08-21T10:23:25.548741 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job BackgroundJobSearchIndex (id=3495357) COMPLETED after 0.0300
I, [2018-08-21T10:23:25.550062 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job BackgroundJobSearchIndex (id=3495358) RUNNING
I, [2018-08-21T10:23:25.577764 #28721]  INFO -- : # curl -X POST "http://127.0.0.1:9200/itszammad01_zammad_production/User/179?pipeline=zammad653674631327" \
I, [2018-08-21T10:23:25.580232 #28721]  INFO -- : # 200
I, [2018-08-21T10:23:25.588212 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job BackgroundJobSearchIndex (id=3495358) COMPLETED after 0.0381
I, [2018-08-21T10:23:25.589637 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job BackgroundJobSearchIndex (id=3495359) RUNNING
I, [2018-08-21T10:23:25.607044 #28721]  INFO -- : # curl -X POST "http://127.0.0.1:9200/itszammad01_zammad_production/User/158?pipeline=zammad653674631327" \
I, [2018-08-21T10:23:25.609614 #28721]  INFO -- : # 200
I, [2018-08-21T10:23:25.617565 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job BackgroundJobSearchIndex (id=3495359) COMPLETED after 0.0278
I, [2018-08-21T10:23:25.619467 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job Transaction::BackgroundJob (id=3495360) RUNNING
I, [2018-08-21T10:23:25.636136 #28721]  INFO -- : 2018-08-21T10:23:25+0200: [Worker(host:itszammad01 pid:28721)] Job Transaction::BackgroundJob (id=3495360) COMPLETED after 0.0166
I, [2018-08-21T10:23:28.117628 #28721]  INFO -- : execute Job.run (try_count 0)...
I, [2018-08-21T10:23:32.189914 #28721]  INFO -- : execute Channel.fetch (try_count 0)...
I, [2018-08-21T10:23:32.191262 #28721]  INFO -- : fetching imap (localhost/vmail port=143,ssl=false,starttls=false,folder=INBOX,keep_on_server=false)
I, [2018-08-21T10:23:32.335217 #28721]  INFO -- :  - no message
I, [2018-08-21T10:23:32.335287 #28721]  INFO -- : done
I, [2018-08-21T10:23:34.015382 #28717]  INFO -- : Started GET "/api/v1/users/image/d7ebeeb9605de5eeabaec56a5d9e0543" for 127.0.0.1 at 2018-08-21 10:23:34 +0200
I, [2018-08-21T10:23:34.018687 #28717]  INFO -- : Processing by UsersController#image as HTML
I, [2018-08-21T10:23:34.018736 #28717]  INFO -- :   Parameters: {"hash"=>"d7ebeeb9605de5eeabaec56a5d9e0543"}
I, [2018-08-21T10:23:34.024717 #28717]  INFO -- :   Rendering text template
I, [2018-08-21T10:23:34.024786 #28717]  INFO -- :   Rendered text template (0.0ms)
I, [2018-08-21T10:23:34.024862 #28717]  INFO -- : Sent data avatar (0.3ms)
I, [2018-08-21T10:23:34.025792 #28717]  INFO -- : Started GET "/api/v1/users/image/38868de3b6849acc46375145f250777c" for 127.0.0.1 at 2018-08-21 10:23:34 +0200
I, [2018-08-21T10:23:34.028489 #28717]  INFO -- : Processing by UsersController#image as HTML
I, [2018-08-21T10:23:34.029075 #28717]  INFO -- : Started GET "/api/v1/users/image/de5985690f4c5cd19de44d79e3aec177" for 127.0.0.1 at 2018-08-21 10:23:34 +0200
I, [2018-08-21T10:23:34.029456 #28717]  INFO -- : Completed 200 OK in 11ms (Views: 0.2ms | ActiveRecord: 3.9ms)
I, [2018-08-21T10:23:34.029515 #28717]  INFO -- :   Parameters: {"hash"=>"38868de3b6849acc46375145f250777c"}
I, [2018-08-21T10:23:34.032236 #28717]  INFO -- : Started GET "/api/v1/users/image/5eae8b4173800331aee90cfa3202de05" for 127.0.0.1 at 2018-08-21 10:23:34 +0200
I, [2018-08-21T10:23:34.040723 #28717]  INFO -- : Processing by UsersController#image as HTML
I, [2018-08-21T10:23:34.041638 #28717]  INFO -- :   Parameters: {"hash"=>"de5985690f4c5cd19de44d79e3aec177"}
I, [2018-08-21T10:23:34.041588 #28717]  INFO -- : Processing by UsersController#image as HTML
I, [2018-08-21T10:23:34.042207 #28717]  INFO -- :   Rendering text template
I, [2018-08-21T10:23:34.043299 #28717]  INFO -- :   Rendered text template (0.0ms)
I, [2018-08-21T10:23:34.043374 #28717]  INFO -- : Sent data avatar (1.3ms)
I, [2018-08-21T10:23:34.043183 #28717]  INFO -- :   Parameters: {"hash"=>"5eae8b4173800331aee90cfa3202de05"}
I, [2018-08-21T10:23:34.045331 #28717]  INFO -- : Completed 200 OK in 13ms (Views: 1.3ms | ActiveRecord: 7.6ms)
I, [2018-08-21T10:23:34.056546 #28717]  INFO -- :   Rendering text template
I, [2018-08-21T10:23:34.056612 #28717]  INFO -- :   Rendered text template (0.0ms)
I, [2018-08-21T10:23:34.056673 #28717]  INFO -- : Sent data avatar (0.3ms)
I, [2018-08-21T10:23:34.057651 #28717]  INFO -- :   Rendering text template
I, [2018-08-21T10:23:34.057716 #28717]  INFO -- :   Rendered text template (0.0ms)
I, [2018-08-21T10:23:34.057774 #28717]  INFO -- : Sent data avatar (0.3ms)
I, [2018-08-21T10:23:34.058526 #28717]  INFO -- : Completed 200 OK in 13ms (Views: 0.2ms | ActiveRecord: 8.1ms)
I, [2018-08-21T10:23:34.059354 #28717]  INFO -- : Completed 200 OK in 17ms (Views: 0.2ms | ActiveRecord: 11.5ms)
I, [2018-08-21T10:23:36.793402 #28717]  INFO -- : Started DELETE "/api/v1/signout" for 127.0.0.1 at 2018-08-21 10:23:36 +0200
I, [2018-08-21T10:23:36.796897 #28717]  INFO -- : Processing by SessionsController#destroy as JSON
I, [2018-08-21T10:23:36.804293 #28717]  INFO -- : Completed 200 OK in 7ms (Views: 0.1ms | ActiveRecord: 2.3ms)
I, [2018-08-21T10:23:42.299399 #28717]  INFO -- : Started POST "/api/v1/signin" for 127.0.0.1 at 2018-08-21 10:23:42 +0200
I, [2018-08-21T10:23:42.303393 #28717]  INFO -- : Processing by SessionsController#create as JSON
I, [2018-08-21T10:23:42.303450 #28717]  INFO -- :   Parameters: {"username"=>"fries", "password"=>"[FILTERED]", "fingerprint"=>"1602471934"}
I, [2018-08-21T10:23:42.567393 #28717]  INFO -- : ldap authentication for user 'fries' (uid) successful!
I, [2018-08-21T10:23:42.571871 #28717]  INFO -- : Authentication against Auth::Ldap for user fries ok.
I, [2018-08-21T10:23:43.219467 #28717]  INFO -- : Completed 201 Created in 916ms (Views: 231.3ms | ActiveRecord: 58.9ms)
I, [2018-08-21T10:23:43.353025 #28717]  INFO -- : Started GET "/api/v1/activity_stream?full=true&limit=25&_=1534839815574" for 127.0.0.1 at 2018-08-21 10:23:43 +0200
I, [2018-08-21T10:23:43.353611 #28717]  INFO -- : Started GET "/api/v1/first_steps?_=1534839815575" for 127.0.0.1 at 2018-08-21 10:23:43 +0200
I, [2018-08-21T10:23:43.357734 #28717]  INFO -- : Processing by ActivityStreamController#show as JSON
I, [2018-08-21T10:23:43.357782 #28717]  INFO -- :   Parameters: {"full"=>"true", "limit"=>"25", "_"=>"1534839815574"}
I, [2018-08-21T10:23:43.360485 #28717]  INFO -- : Processing by FirstStepsController#index as JSON
I, [2018-08-21T10:23:43.360527 #28717]  INFO -- :   Parameters: {"_"=>"1534839815575"}
I, [2018-08-21T10:23:43.378910 #28717]  INFO -- : Completed 200 OK in 18ms (Views: 0.3ms | ActiveRecord: 10.7ms)
I, [2018-08-21T10:23:43.692160 #28717]  INFO -- : Completed 200 OK in 334ms (Views: 206.4ms | ActiveRecord: 21.0ms)
I, [2018-08-21T10:23:43.997755 #28717]  INFO -- : Started GET "/api/v1/cti/log?_=1534839815576" for 127.0.0.1 at 2018-08-21 10:23:43 +0200
I, [2018-08-21T10:23:44.001170 #28717]  INFO -- : Processing by CtiController#index as JSON
I, [2018-08-21T10:23:44.001222 #28717]  INFO -- :   Parameters: {"_"=>"1534839815576"}
I, [2018-08-21T10:23:44.361879 #28717]  INFO -- : Completed 200 OK in 361ms (Views: 323.4ms | ActiveRecord: 1.9ms)
I, [2018-08-21T10:23:44.552052 #28717]  INFO -- : Started GET "/api/v1/users/4?full=true&_=1534831441447" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.553941 #28717]  INFO -- : Started GET "/api/v1/users/10?full=true&_=1534831441448" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.555252 #28717]  INFO -- : Started GET "/api/v1/users/6?full=true&_=1534831441449" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.556620 #28717]  INFO -- : Started GET "/api/v1/users/9?full=true&_=1534831441450" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.560087 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.560134 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534831441450", "id"=>"9"}
I, [2018-08-21T10:23:44.562765 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.562809 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534831441448", "id"=>"10"}
I, [2018-08-21T10:23:44.564803 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.564844 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534831441449", "id"=>"6"}
I, [2018-08-21T10:23:44.567652 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.567694 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534831441447", "id"=>"4"}
I, [2018-08-21T10:23:44.568648 #28717]  INFO -- : Started GET "/api/v1/users/4?full=true&_=1534836897934" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.570785 #28717]  INFO -- : Started GET "/api/v1/users/6?full=true&_=1534836897935" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.572263 #28717]  INFO -- : Started GET "/api/v1/users/4?full=true&_=1534832378195" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.573687 #28717]  INFO -- : Started GET "/api/v1/users/6?full=true&_=1534832378196" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.575242 #28717]  INFO -- : Started GET "/api/v1/users/9?full=true&_=1534832378197" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.576554 #28717]  INFO -- : Started GET "/api/v1/users/11?full=true&_=1534832378198" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.577957 #28717]  INFO -- : Started GET "/api/v1/users/7?full=true&_=1534832378199" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.579292 #28717]  INFO -- : Started GET "/api/v1/users/4?full=true&_=1534833187527" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.583280 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.583344 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534832378197", "id"=>"9"}
I, [2018-08-21T10:23:44.587099 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.587165 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534832378195", "id"=>"4"}
I, [2018-08-21T10:23:44.591920 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.591990 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534833187527", "id"=>"4"}
I, [2018-08-21T10:23:44.595988 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.596053 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534832378199", "id"=>"7"}
I, [2018-08-21T10:23:44.599637 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.599696 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534832378198", "id"=>"11"}
I, [2018-08-21T10:23:44.604781 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.604855 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534832378196", "id"=>"6"}
I, [2018-08-21T10:23:44.608701 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.608775 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534836897934", "id"=>"4"}
I, [2018-08-21T10:23:44.612304 #28717]  INFO -- : Processing by UsersController#show as JSON
I, [2018-08-21T10:23:44.612371 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534836897935", "id"=>"6"}
I, [2018-08-21T10:23:44.825684 #28717]  INFO -- : Started GET "/api/v1/users/search?sort_by=created_at&query=*&limit=50&full=true&_=1534839815578" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:44.867739 #28717]  INFO -- : Processing by UsersController#search as JSON
I, [2018-08-21T10:23:44.867809 #28717]  INFO -- :   Parameters: {"sort_by"=>"created_at", "query"=>"*", "limit"=>"50", "full"=>"true", "_"=>"1534839815578"}
I, [2018-08-21T10:23:44.870693 #28717]  INFO -- : Started GET "/api/v1/ticket_create?_=1534839815577" for 127.0.0.1 at 2018-08-21 10:23:44 +0200
I, [2018-08-21T10:23:45.007912 #28717]  INFO -- : Processing by TicketsController#ticket_create as JSON
I, [2018-08-21T10:23:45.007985 #28717]  INFO -- :   Parameters: {"_"=>"1534839815577"}
I, [2018-08-21T10:23:45.119087 #28717]  INFO -- : Completed 200 OK in 519ms (Views: 16.9ms | ActiveRecord: 320.5ms)
I, [2018-08-21T10:23:45.153522 #28717]  INFO -- : Completed 200 OK in 586ms (Views: 5.6ms | ActiveRecord: 306.8ms)
I, [2018-08-21T10:23:45.154664 #28717]  INFO -- : Completed 200 OK in 550ms (Views: 6.6ms | ActiveRecord: 349.8ms)
I, [2018-08-21T10:23:45.161829 #28717]  INFO -- : Completed 200 OK in 602ms (Views: 4.9ms | ActiveRecord: 342.9ms)
I, [2018-08-21T10:23:45.163537 #28717]  INFO -- : Completed 200 OK in 551ms (Views: 5.2ms | ActiveRecord: 319.4ms)
I, [2018-08-21T10:23:45.170862 #28717]  INFO -- : Completed 200 OK in 587ms (Views: 15.6ms | ActiveRecord: 142.3ms)
I, [2018-08-21T10:23:45.171798 #28717]  INFO -- : Completed 200 OK in 585ms (Views: 5.8ms | ActiveRecord: 300.3ms)
I, [2018-08-21T10:23:45.174476 #28717]  INFO -- : # curl -X POST "http://127.0.0.1:9200/itszammad01_zammad_production/Ticket/_search" \
I, [2018-08-21T10:23:45.178843 #28717]  INFO -- : Completed 200 OK in 570ms (Views: 7.0ms | ActiveRecord: 288.8ms)
I, [2018-08-21T10:23:45.188966 #28717]  INFO -- : Completed 200 OK in 593ms (Views: 5.1ms | ActiveRecord: 274.2ms)
I, [2018-08-21T10:23:45.190960 #28717]  INFO -- : Completed 200 OK in 599ms (Views: 5.4ms | ActiveRecord: 305.9ms)
I, [2018-08-21T10:23:45.193139 #28717]  INFO -- : Completed 200 OK in 628ms (Views: 5.2ms | ActiveRecord: 279.4ms)
I, [2018-08-21T10:23:45.194117 #28717]  INFO -- : Completed 200 OK in 631ms (Views: 5.4ms | ActiveRecord: 267.9ms)
I, [2018-08-21T10:23:45.408436 #28717]  INFO -- : Started GET "/api/v1/ticket_customer?customer_id=8&_=1534833187528" for 127.0.0.1 at 2018-08-21 10:23:45 +0200
I, [2018-08-21T10:23:45.420864 #28717]  INFO -- : Processing by TicketsController#ticket_customer as JSON
I, [2018-08-21T10:23:45.420937 #28717]  INFO -- :   Parameters: {"customer_id"=>"8", "_"=>"1534833187528"}
I, [2018-08-21T10:23:45.526234 #28717]  INFO -- : Completed 200 OK in 518ms (Views: 6.2ms | ActiveRecord: 458.8ms)
I, [2018-08-21T10:23:45.562870 #28717]  INFO -- : # 200
I, [2018-08-21T10:23:45.562930 #28717]  INFO -- : ... Ticket 914
I, [2018-08-21T10:23:45.562970 #28717]  INFO -- : ... Ticket 915
I, [2018-08-21T10:23:45.562990 #28717]  INFO -- : ... Ticket 913
I, [2018-08-21T10:23:45.563007 #28717]  INFO -- : ... Ticket 912
I, [2018-08-21T10:23:45.563023 #28717]  INFO -- : ... Ticket 911
I, [2018-08-21T10:23:45.563038 #28717]  INFO -- : ... Ticket 873
I, [2018-08-21T10:23:45.563057 #28717]  INFO -- : ... Ticket 910
I, [2018-08-21T10:23:45.563074 #28717]  INFO -- : ... Ticket 896
I, [2018-08-21T10:23:45.563087 #28717]  INFO -- : ... Ticket 905
I, [2018-08-21T10:23:45.563101 #28717]  INFO -- : ... Ticket 732
I, [2018-08-21T10:23:45.563114 #28717]  INFO -- : ... Ticket 901
I, [2018-08-21T10:23:45.563127 #28717]  INFO -- : ... Ticket 909
I, [2018-08-21T10:23:45.563140 #28717]  INFO -- : ... Ticket 904
I, [2018-08-21T10:23:45.563153 #28717]  INFO -- : ... Ticket 874
I, [2018-08-21T10:23:45.563166 #28717]  INFO -- : ... Ticket 907
I, [2018-08-21T10:23:45.563182 #28717]  INFO -- : ... Ticket 883
I, [2018-08-21T10:23:45.563195 #28717]  INFO -- : ... Ticket 908
I, [2018-08-21T10:23:45.563209 #28717]  INFO -- : ... Ticket 903
I, [2018-08-21T10:23:45.563221 #28717]  INFO -- : ... Ticket 906
I, [2018-08-21T10:23:45.563234 #28717]  INFO -- : ... Ticket 902
I, [2018-08-21T10:23:45.563247 #28717]  INFO -- : ... Ticket 193
I, [2018-08-21T10:23:45.563261 #28717]  INFO -- : ... Ticket 548
I, [2018-08-21T10:23:45.563274 #28717]  INFO -- : ... Ticket 674
I, [2018-08-21T10:23:45.563287 #28717]  INFO -- : ... Ticket 484
I, [2018-08-21T10:23:45.563302 #28717]  INFO -- : ... Ticket 789
I, [2018-08-21T10:23:45.563316 #28717]  INFO -- : ... Ticket 860
I, [2018-08-21T10:23:45.563328 #28717]  INFO -- : ... Ticket 899
I, [2018-08-21T10:23:45.563341 #28717]  INFO -- : ... Ticket 897
I, [2018-08-21T10:23:45.563354 #28717]  INFO -- : ... Ticket 898
I, [2018-08-21T10:23:45.563367 #28717]  INFO -- : ... Ticket 900
I, [2018-08-21T10:23:45.563379 #28717]  INFO -- : ... Ticket 884
I, [2018-08-21T10:23:45.563394 #28717]  INFO -- : ... Ticket 839
I, [2018-08-21T10:23:45.563406 #28717]  INFO -- : ... Ticket 895
I, [2018-08-21T10:23:45.563421 #28717]  INFO -- : ... Ticket 894
I, [2018-08-21T10:23:45.563434 #28717]  INFO -- : ... Ticket 876
I, [2018-08-21T10:23:45.563446 #28717]  INFO -- : ... Ticket 889
I, [2018-08-21T10:23:45.563459 #28717]  INFO -- : ... Ticket 881
I, [2018-08-21T10:23:45.563474 #28717]  INFO -- : ... Ticket 891
I, [2018-08-21T10:23:45.563488 #28717]  INFO -- : ... Ticket 893
I, [2018-08-21T10:23:45.563503 #28717]  INFO -- : ... Ticket 747
I, [2018-08-21T10:23:45.563516 #28717]  INFO -- : ... Ticket 892
I, [2018-08-21T10:23:45.563529 #28717]  INFO -- : ... Ticket 871
I, [2018-08-21T10:23:45.563542 #28717]  INFO -- : ... Ticket 890
I, [2018-08-21T10:23:45.563554 #28717]  INFO -- : ... Ticket 850
I, [2018-08-21T10:23:45.563567 #28717]  INFO -- : ... Ticket 880
I, [2018-08-21T10:23:45.563580 #28717]  INFO -- : ... Ticket 888
I, [2018-08-21T10:23:45.563592 #28717]  INFO -- : ... Ticket 887
I, [2018-08-21T10:23:45.563606 #28717]  INFO -- : ... Ticket 886
I, [2018-08-21T10:23:45.563618 #28717]  INFO -- : ... Ticket 885
I, [2018-08-21T10:23:45.563631 #28717]  INFO -- : ... Ticket 882
I, [2018-08-21T10:23:45.602252 #28717]  INFO -- : # curl -X POST "http://127.0.0.1:9200/itszammad01_zammad_production/User/_search" \
I, [2018-08-21T10:23:45.619906 #28717]  INFO -- : # 200
I, [2018-08-21T10:23:45.619966 #28717]  INFO -- : ... User 303
I, [2018-08-21T10:23:45.619987 #28717]  INFO -- : ... User 302
I, [2018-08-21T10:23:45.620002 #28717]  INFO -- : ... User 301
I, [2018-08-21T10:23:45.620016 #28717]  INFO -- : ... User 300
I, [2018-08-21T10:23:45.620029 #28717]  INFO -- : ... User 299
I, [2018-08-21T10:23:45.620042 #28717]  INFO -- : ... User 298
I, [2018-08-21T10:23:45.620054 #28717]  INFO -- : ... User 297
I, [2018-08-21T10:23:45.620067 #28717]  INFO -- : ... User 296
I, [2018-08-21T10:23:45.620080 #28717]  INFO -- : ... User 295
I, [2018-08-21T10:23:45.620092 #28717]  INFO -- : ... User 294
I, [2018-08-21T10:23:45.620105 #28717]  INFO -- : ... User 293
I, [2018-08-21T10:23:45.620137 #28717]  INFO -- : ... User 292
I, [2018-08-21T10:23:45.620152 #28717]  INFO -- : ... User 291
I, [2018-08-21T10:23:45.620165 #28717]  INFO -- : ... User 290
I, [2018-08-21T10:23:45.620177 #28717]  INFO -- : ... User 289
I, [2018-08-21T10:23:45.620190 #28717]  INFO -- : ... User 288
I, [2018-08-21T10:23:45.620202 #28717]  INFO -- : ... User 287
I, [2018-08-21T10:23:45.620218 #28717]  INFO -- : ... User 286
I, [2018-08-21T10:23:45.620231 #28717]  INFO -- : ... User 285
I, [2018-08-21T10:23:45.620243 #28717]  INFO -- : ... User 284
I, [2018-08-21T10:23:45.620256 #28717]  INFO -- : ... User 283
I, [2018-08-21T10:23:45.620269 #28717]  INFO -- : ... User 282
I, [2018-08-21T10:23:45.620282 #28717]  INFO -- : ... User 281
I, [2018-08-21T10:23:45.620294 #28717]  INFO -- : ... User 280
I, [2018-08-21T10:23:45.620306 #28717]  INFO -- : ... User 279
I, [2018-08-21T10:23:45.620320 #28717]  INFO -- : ... User 278
I, [2018-08-21T10:23:45.620333 #28717]  INFO -- : ... User 277
I, [2018-08-21T10:23:45.620353 #28717]  INFO -- : ... User 276
I, [2018-08-21T10:23:45.620369 #28717]  INFO -- : ... User 275
I, [2018-08-21T10:23:45.620384 #28717]  INFO -- : ... User 274
I, [2018-08-21T10:23:45.620399 #28717]  INFO -- : ... User 273
I, [2018-08-21T10:23:45.620413 #28717]  INFO -- : ... User 272
I, [2018-08-21T10:23:45.620427 #28717]  INFO -- : ... User 271
I, [2018-08-21T10:23:45.620442 #28717]  INFO -- : ... User 270
I, [2018-08-21T10:23:45.620456 #28717]  INFO -- : ... User 269
I, [2018-08-21T10:23:45.620471 #28717]  INFO -- : ... User 268
I, [2018-08-21T10:23:45.620484 #28717]  INFO -- : ... User 267
I, [2018-08-21T10:23:45.620497 #28717]  INFO -- : ... User 266
I, [2018-08-21T10:23:45.620510 #28717]  INFO -- : ... User 265
I, [2018-08-21T10:23:45.620523 #28717]  INFO -- : ... User 264
I, [2018-08-21T10:23:45.620536 #28717]  INFO -- : ... User 263
I, [2018-08-21T10:23:45.620548 #28717]  INFO -- : ... User 262
I, [2018-08-21T10:23:45.620561 #28717]  INFO -- : ... User 261
I, [2018-08-21T10:23:45.620573 #28717]  INFO -- : ... User 260
I, [2018-08-21T10:23:45.620585 #28717]  INFO -- : ... User 259
I, [2018-08-21T10:23:45.620597 #28717]  INFO -- : ... User 258
I, [2018-08-21T10:23:45.620609 #28717]  INFO -- : ... User 257
I, [2018-08-21T10:23:45.620621 #28717]  INFO -- : ... User 256
I, [2018-08-21T10:23:45.620634 #28717]  INFO -- : ... User 255
I, [2018-08-21T10:23:45.620646 #28717]  INFO -- : ... User 254
I, [2018-08-21T10:23:45.678867 #28717]  INFO -- : Completed 200 OK in 258ms (Views: 25.0ms | ActiveRecord: 17.7ms)
I, [2018-08-21T10:23:45.973205 #28717]  INFO -- : Started GET "/api/v1/text_modules/?full=true&_=1534839815579" for 127.0.0.1 at 2018-08-21 10:23:45 +0200
I, [2018-08-21T10:23:45.980778 #28717]  INFO -- : Processing by TextModulesController#index as JSON
I, [2018-08-21T10:23:45.980857 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534839815579"}
I, [2018-08-21T10:23:45.984072 #28717]  INFO -- : Completed 200 OK in 1116ms (Views: 136.6ms | ActiveRecord: 312.8ms)
I, [2018-08-21T10:23:46.013912 #28717]  INFO -- : Completed 200 OK in 33ms (Views: 8.1ms | ActiveRecord: 5.2ms)
I, [2018-08-21T10:23:46.521391 #28717]  INFO -- : Started GET "/api/v1/settings/?full=true&_=1534839815580" for 127.0.0.1 at 2018-08-21 10:23:46 +0200
I, [2018-08-21T10:23:46.524458 #28717]  INFO -- : Processing by SettingsController#index as JSON
I, [2018-08-21T10:23:46.524500 #28717]  INFO -- :   Parameters: {"full"=>"true", "_"=>"1534839815580"}
E, [2018-08-21T10:23:46.765501 #28717] ERROR -- : "\xC2" from ASCII-8BIT to UTF-8 (Encoding::UndefinedConversionError)
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:36:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:55:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/json-2.1.0/lib/json/common.rb:224:in `generate'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/json-2.1.0/lib/json/common.rb:224:in `generate'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:100:in `stringify'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:33:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/json/encoding.rb:20:in `encode'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/object/json.rb:39:in `to_json'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:156:in `block in <module:Renderers>'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:149:in `block in _render_to_body_with_renderer'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/set.rb:324:in `each_key'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/set.rb:324:in `each'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:145:in `_render_to_body_with_renderer'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/renderers.rb:141:in `render_to_body'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/rendering.rb:24:in `render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rendering.rb:36:in `render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/benchmark.rb:12:in `block in ms'
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/benchmark.rb:308:in `realtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/core_ext/benchmark.rb:12:in `ms'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:44:in `block in render'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:87:in `cleanup_view_runtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.5/lib/active_record/railties/controller_runtime.rb:29:in `cleanup_view_runtime'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:43:in `render'
/opt/zammad/app/controllers/settings_controller.rb:13:in `index'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/base.rb:186:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rendering.rb:30:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.5/lib/active_support/callbacks.rb:131:in `run_callbacks'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/abstract_controller/callbacks.rb:19:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/rescue.rb:20:in `process_action'
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.5/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'

thorsteneckel · August 21, 2018, 1:05pm

Hi @MamoulianDelacroix - Please do the following:

Disable the LDAP sync
replace the file
restart your Zammad application services
reset your LDAP config
re-configure your LDAP sync
re-activate the LDAP sync