, [2019-04-10T16:09:15.868577 #21092-70210171752840] INFO – : Parameters: {“customer_id”=>“3894”, “"=>“1554886430068”}
I, [2019-04-10T16:09:15.978852 #21092-70210032932800] INFO – : Started GET "/api/v1/ticket_customer?customer_id=389&=155488069” for ****** at 2019-04-10 16:09:15 +0200
I, [2019-04-10T16:09:16.002424 #21092-70210032932800] INFO – : Processing by TicketsController#ticket_customer as JSON
I, [2019-04-10T16:09:16.003481 #21092-70210032932800] INFO – : Parameters: {“customer_id”=>“389”, “"=>“1554886439”}
I, [2019-04-10T16:09:16.013963 #21092-47156859389800] INFO – : Started GET "/api/v1/ticket_customer?customer_id=389&=155480070” for ****** at 2019-04-10 16:09:16 +0200
I, [2019-04-10T16:09:16.046178 #21092-47156859389800] INFO – : Processing by TicketsController#ticket_customer as JSON
I, [2019-04-10T16:09:16.046647 #21092-47156859389800] INFO – : Parameters: {“customer_id”=>“389”, “_”=>“15548860070”}
I, [2019-04-10T16:09:16.160368 #21092-70210171752840] INFO – : Completed 200 OK in 291ms (Views: 73.5ms | ActiveRecord: 19.6ms)
I, [2019-04-10T16:09:16.542856 #21092-70210032932800] INFO – : Completed 200 OK in 539ms (Views: 94.6ms | ActiveRecord: 62.4ms)
I, [2019-04-10T16:09:16.950939 #21092-47156859389800] INFO – : Completed 200 OK in 904ms (Views: 392.0ms | ActiveRecord: 131.5ms)
I, [2019-04-10T16:09:21.939099 #21094-47000454754180] INFO – : Running job thread for ‘Execute jobs’ (Job.run) status is: sleep
I, [2019-04-10T16:09:22.815921 #21094-69930862307100] INFO – : execute Channel.fetch (try_count 0)…
I, [2019-04-10T16:09:22.831396 #21094-69930862307100] INFO – : fetching imap ()
I, [2019-04-10T16:09:23.195378 #21094-69930862307100] INFO – : - no message
I, [2019-04-10T16:09:23.195932 #21094-69930862307100] INFO – : done
E, [2019-04-10T16:09:31.534623 #21094-69930862307100] ERROR – : Can’t use Channel::Driver::Imap: #<Net::IMAP::NoResponseError: Authentication failed.>
E, [2019-04-10T16:09:31.534994 #21094-69930862307100] ERROR – : Authentication failed. (Net::IMAP::NoResponseError)
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/net/imap.rb:1194:in get_tagged_response' /opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/net/imap.rb:1248:in
block in send_command’
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/monitor.rb:214:in mon_synchronize' /opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/net/imap.rb:1230:in
send_command’
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/net/imap.rb:434:in login' /opt/zammad/app/models/channel/driver/imap.rb:110:in
block in fetch’
/opt/zammad/app/models/channel/driver/imap.rb:381:in block in timeout' /opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/timeout.rb:93:in
block in timeout’
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/timeout.rb:33:in block in catch' /opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/timeout.rb:33:in
catch’
/opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/timeout.rb:33:in catch' /opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/timeout.rb:108:in
timeout’
/opt/zammad/app/models/channel/driver/imap.rb:380:in timeout' /opt/zammad/app/models/channel/driver/imap.rb:109:in
fetch’
/opt/zammad/app/models/channel.rb:56:in fetch' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/relation/delegation.rb:39:in
each’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/relation/delegation.rb:39:in each' /opt/zammad/app/models/channel.rb:30:in
fetch’
(eval):1:in _start_job' /opt/zammad/app/models/scheduler.rb:286:in
eval’
/opt/zammad/app/models/scheduler.rb:286:in _start_job' /opt/zammad/app/models/scheduler.rb:239:in
block (2 levels) in start_job’
/opt/zammad/app/models/scheduler.rb:237:in loop' /opt/zammad/app/models/scheduler.rb:237:in
block in start_job’
/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, [2019-04-10T16:09:31.778880 #21094-69930862307100] INFO -- : fetching imap () E, [2019-04-10T16:09:34.338303 #21094-69931131225380] ERROR -- : Email address is already used for other user. (Exceptions::UnprocessableEntity) /opt/zammad/app/models/user.rb:1036:in
ensure_uniq_email’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:413:in block in make_lambda' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:197:in
block (2 levels) in halting’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:601:in block (2 levels) in default_terminator' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:600:in
catch’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:600:in block in default_terminator' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:198:in
block in halting’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:507:in block in invoke_before' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:507:in
each’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:507:in invoke_before' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:130:in
run_callbacks’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.6.2/lib/active_support/callbacks.rb:827:in _run_validation_callbacks' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activemodel-5.1.6.2/lib/active_model/validations/callbacks.rb:114:in
run_validations!’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activemodel-5.1.6.2/lib/active_model/validations.rb:335:in valid?' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/validations.rb:65:in
valid?’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/validations.rb:82:in perform_validations' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/validations.rb:50:in
save!’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/attribute_methods/dirty.rb:43:in save!' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/transactions.rb:313:in
block in save!’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/transactions.rb:384:in block in with_transaction_returning_status' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in
block in transaction’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/connection_adapters/abstract/transaction.rb:194:in block in within_new_transaction' /opt/zammad/vendor/ruby-2.4.4/lib/ruby/2.4.0/monitor.rb:214:in
mon_synchronize’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/connection_adapters/abstract/transaction.rb:191:in within_new_transaction' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in
transaction’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/transactions.rb:210:in transaction' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/transactions.rb:381:in
with_transaction_returning_status’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/transactions.rb:313:in save!' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/suppressor.rb:46:in
save!’
/opt/zammad/lib/sequencer/unit/import/common/model/save.rb:21:in process' /opt/zammad/lib/sequencer/unit/import/common/model/mixin/skip/action.rb:47:in
process’
/opt/zammad/lib/sequencer/unit/import/common/model/mixin/without_callback.rb:28:in block in process' /opt/zammad/lib/core_ext/activesupport/lib/active_support/callbacks.rb:27:in
without_callback’
/opt/zammad/lib/sequencer/unit/import/common/model/mixin/without_callback.rb:41:in block (2 levels) in process' /opt/zammad/lib/core_ext/activesupport/lib/active_support/callbacks.rb:27:in
without_callback’
/opt/zammad/lib/sequencer/unit/import/common/model/mixin/without_callback.rb:41:in block (2 levels) in process' /opt/zammad/lib/sequencer/unit/import/common/model/mixin/without_callback.rb:47:in
process’
/opt/zammad/lib/sequencer/unit/base.rb:202:in process' /opt/zammad/lib/sequencer.rb:77:in
block (4 levels) in process’
/opt/zammad/lib/mixin/start_finish_logger.rb:7:in log_start_finish' /opt/zammad/lib/sequencer.rb:76:in
block (3 levels) in process’
/opt/zammad/lib/sequencer/state.rb:150:in process' /opt/zammad/lib/sequencer.rb:74:in
block (2 levels) in process’
/opt/zammad/lib/sequencer/units.rb:29:in block in each' /opt/zammad/lib/sequencer/units.rb:28:in
each’
/opt/zammad/lib/sequencer/units.rb:28:in each' /opt/zammad/lib/sequencer.rb:72:in
each_with_index’
/opt/zammad/lib/sequencer.rb:72:in block in process' /opt/zammad/lib/mixin/start_finish_logger.rb:7:in
log_start_finish’
/opt/zammad/lib/sequencer.rb:70:in process' /opt/zammad/lib/sequencer.rb:25:in
process’
/opt/zammad/lib/sequencer/unit/import/common/sub_sequence/mixin/base.rb:34:in sequence_resource' /opt/zammad/lib/sequencer/unit/import/ldap/users/sub_sequence.rb:17:in
block in process’
/opt/zammad/lib/ldap.rb:79:in block in search' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap.rb:786:in
block (3 levels) in search’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap/connection.rb:445:in block (2 levels) in search' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap/connection.rb:399:in
loop’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap/connection.rb:399:in block in search' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap/instrumentation.rb:19:in
instrument’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap/connection.rb:388:in search' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap.rb:784:in
block (2 levels) in search’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap.rb:1303:in use_connection' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap.rb:783:in
block in search’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap/instrumentation.rb:19:in instrument' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/net-ldap-0.16.1/lib/net/ldap.rb:782:in
search’
/opt/zammad/lib/ldap.rb:72:in search' /opt/zammad/lib/sequencer/unit/import/ldap/users/sub_sequence.rb:15:in
process’
/opt/zammad/lib/sequencer/unit/base.rb:202:in process' /opt/zammad/lib/sequencer.rb:77:in
block (4 levels) in process’
/opt/zammad/lib/mixin/start_finish_logger.rb:7:in log_start_finish' /opt/zammad/lib/sequencer.rb:76:in
block (3 levels) in process’
/opt/zammad/lib/sequencer/state.rb:150:in process' /opt/zammad/lib/sequencer.rb:74:in
block (2 levels) in process’
/opt/zammad/lib/sequencer/units.rb:29:in block in each' /opt/zammad/lib/sequencer/units.rb:28:in
each’
/opt/zammad/lib/sequencer/units.rb:28:in each' /opt/zammad/lib/sequencer.rb:72:in
each_with_index’
/opt/zammad/lib/sequencer.rb:72:in block in process' /opt/zammad/lib/mixin/start_finish_logger.rb:7:in
log_start_finish’
/opt/zammad/lib/sequencer.rb:70:in process' /opt/zammad/lib/sequencer.rb:25:in
process’
/opt/zammad/lib/import/mixin/sequence.rb:15:in process' /opt/zammad/lib/import/integration_base.rb:99:in
start’
/opt/zammad/app/models/import_job.rb:24:in start' /opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/relation/delegation.rb:39:in
each’
/opt/zammad/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.6.2/lib/active_record/relation/delegation.rb:39:in each' /opt/zammad/app/models/import_job.rb:105:in
start’
/opt/zammad/app/models/import_job.rb:95:in start_registered' (eval):1:in
_start_job’
/opt/zammad/app/models/scheduler.rb:286:in eval' /opt/zammad/app/models/scheduler.rb:286:in
_start_job’
/opt/zammad/app/models/scheduler.rb:258:in block in start_job' /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, [2019-04-10T16:09:37.237775 #21092-47156864900580] INFO – : Completed 200 OK in 26183ms (Views: 2.8ms | ActiveRecord: 43.3ms)
I, [2019-04-10T16:09:37.403793 #21092-70210000225360] INFO – : Completed 200 OK in 26261ms (Views: 0.9ms | ActiveRecord: 23.0ms)
I, [2019-04-10T16:09:37.407813 #21092-47156866049940] INFO – : Completed 200 OK in 26255ms (Views: 0.4ms | ActiveRecord: 30.2ms)
I, [2019-04-10T16:09:37.465825 #21094-69930862307100] INFO – : - no message
I, [2019-04-10T16:09:37.489265 #21094-69930862307100] INFO – : done
I, [2019-04-10T16:09:37.490214 #21092-70210369432960] INFO – : Completed 200 OK in 26360ms (Views: 0.6ms | ActiveRecord: 41.3ms)
I, [2019-04-10T16:09:37.574398 #21092-47156854363840] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:37 +0200
I, [2019-04-10T16:09:37.589423 #21092-47156854363840] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:37.589993 #21092-47156854363840] INFO – : Parameters: {“client_id”=>“"}
I, [2019-04-10T16:09:37.633461 #21092-70210672078180] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:37 +0200
I, [2019-04-10T16:09:37.648996 #21092-70210672078180] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:37.649306 #21092-70210672078180] INFO – : Parameters: {“client_id”=>"”}
I, [2019-04-10T16:09:37.719855 #21092-47156859437780] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:37 +0200
I, [2019-04-10T16:09:37.734885 #21092-47156859437780] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:37.737354 #21092-70210402771820] INFO – : Completed 200 OK in 26227ms (Views: 0.4ms | ActiveRecord: 24.2ms)
I, [2019-04-10T16:09:37.737695 #21092-47156859437780] INFO – : Parameters: {“client_id”=>“"}
I, [2019-04-10T16:09:37.914216 #21092-70210636229400] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:37 +0200
I, [2019-04-10T16:09:37.928051 #21092-70210636229400] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:37.928348 #21092-70210636229400] INFO – : Parameters: {“client_id”=>"”}
I, [2019-04-10T16:09:38.075834 #21092-70209704478560] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:38 +0200
I, [2019-04-10T16:09:38.100347 #21092-70209704478560] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:38.100793 #21092-70209704478560] INFO – : Parameters: {“client_id”=>“"}
I, [2019-04-10T16:09:38.428338 #21092-47156829954160] INFO – : Completed 200 OK in 26052ms (Views: 1.0ms | ActiveRecord: 5.8ms)
I, [2019-04-10T16:09:38.494953 #21092-47156847462900] INFO – : Completed 200 OK in 26002ms (Views: 1.2ms | ActiveRecord: 18.8ms)
I, [2019-04-10T16:09:38.675715 #21092-70210672078180] INFO – : Completed 200 OK in 1026ms (Views: 0.9ms | ActiveRecord: 5.1ms)
I, [2019-04-10T16:09:38.692150 #21092-47156816516920] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:38 +0200
I, [2019-04-10T16:09:38.734236 #21092-47156816516920] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:38.734665 #21092-47156816516920] INFO – : Parameters: {“client_id”=>"”}
I, [2019-04-10T16:09:38.752170 #21094-69931131225380] INFO – : Enqueued SearchIndexJob (Job ID: f1691c-eb09-4ba-b12-08fb128c) to DelayedJob(default) with arguments: “User”, 4144
I, [2019-04-10T16:09:38.755240 #21092-70210132773480] INFO – : Completed 200 OK in 26082ms (Views: 0.5ms | ActiveRecord: 13.5ms)
I, [2019-04-10T16:09:38.757742 #21092-70210032935700] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:38 +0200
I, [2019-04-10T16:09:38.793891 #21092-47156859437780] INFO – : Completed 200 OK in 1053ms (Views: 0.6ms | ActiveRecord: 6.4ms)
I, [2019-04-10T16:09:38.807939 #21092-70210032935700] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:38.808446 #21092-70210032935700] INFO – : Parameters: {“client_id”=>""}
I, [2019-04-10T16:09:38.904472 #21092-47156866210240] INFO – : Completed 200 OK in 26124ms (Views: 0.6ms | ActiveRecord: 58.3ms)
I, [2019-04-10T16:09:39.003376 #21094-47000521192020] INFO – : 2019-04-10T16:09:39+0200: [Worker(host:** pid:21094)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2946736) (queue=default) RUNNING
I, [2019-04-10T16:09:39.312725 #21092-70210171752840] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:39 +0200
I, [2019-04-10T16:09:39.327327 #21092-70210032932800] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:39 +0200
I, [2019-04-10T16:09:39.342974 #21092-47156859389800] INFO – : Started POST “/api/v1/message_receive” for ****** at 2019-04-10 16:09:39 +0200
I, [2019-04-10T16:09:39.352067 #21092-70210032932800] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:39.361137 #21092-70210171752840] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:39.376324 #21092-70210032932800] INFO – : Parameters: {“client_id”=>“"}
I, [2019-04-10T16:09:39.383771 #21092-70209704478560] INFO – : Completed 200 OK in 1282ms (Views: 0.8ms | ActiveRecord: 22.0ms)
I, [2019-04-10T16:09:39.394113 #21092-47156859389800] INFO – : Processing by LongPollingController#message_receive as JSON
I, [2019-04-10T16:09:39.417603 #21094-47000521192020] INFO – : Performing SearchIndexJob (Job ID: f16ee91c-eb09-4ba-b12-08fb128c) from DelayedJob(default) with arguments: “User”, 4144
I, [2019-04-10T16:09:39.394652 #21092-70210171752840] INFO – : Parameters: {“client_id”=>"”}