Microsoft 365 fails with 500 Xoauth2 token error

Infos:

  • Used Zammad version: 3.6.x
  • Used Zammad installation source: package (debian 9)
  • Operating system: Debian 9 Stretch
  • Browser + version: Firefox 82.0.3 Ubuntu 20.04

Expected behavior:

I’ve setup Microsoft 365 yesterday by following the guide in the admin docs and migrated our email channel accounts to M365. This worked perfectly.
While today I tried to send a reply to a ticket and I expected it to go out.

Actual behavior:

It actually didn’t gone out but when I checked Microsoft 365 channel (or Monitoring tab) both don’t show any accounts or something but immediately reply with a popup (that reoccurs every other second) saying:

StatusCode: 500

{“error”:“Failed to refresh XOAUTH2 access_token of provider ‘microsoft365’! #\u003cRuntimeError: Request failed! ERROR: invalid_grant (AADSTS50173: The provided grant has expired due to it being revoked, a fresh auth token is needed. The user might have changed or reset their password. The grant was issued on ‘2020-11-17T12:24:29.9095532Z’ and the TokensValidFrom date (before which tokens are not valid) for this user is ‘2020-11-17T16:27:52.0000000Z’.\r\nTrace ID: d0b8d259-58df-4305-8e66-65e3dcdf4400\r\nCorrelation ID: b5d24d10-b781-4bdb-ad27-624f20556066\r\nTimestamp: 2020-11-18 07:50:22Z)\u003e”}

I’m quite sure that I didn’t changed any passwords, and the App registrations are still there with “never” ending client tokens

Full Log:
, [2020-11-18T09:35:21.181275 #29739-69963139157800] ERROR – : Failed to refresh XOAUTH2 access_token of provider ‘microsoft365’! #<RuntimeError: Request failed! ERROR: invalid_grant (AADSTS50173: The provided grant has expired due to it being revoked, a fresh auth token is needed. The user might have changed or reset their password. The grant was issued on ‘2020-11-17T12:24:29.9095532Z’ and the TokensValidFrom date (before which tokens are not valid) for this user is ‘2020-11-18T08:24:12.0000000Z’.
Trace ID: 9d9d2faf-baae-4b90-a5e6-a422380f3800
Correlation ID: 545454c4-8f7b-40d7-a049-0bad79d4a90d
Timestamp: 2020-11-18 08:35:21Z)> (RuntimeError)
/opt/zammad/app/models/channel.rb:359:in rescue in refresh_xoaut2!' /opt/zammad/app/models/channel.rb:339:in refresh_xoaut2!’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:426:in block in make_lambda' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:236:in block in halting_and_conditional’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:517:in block in invoke_after' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:517:in each’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:517:in invoke_after' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:133:in run_callbacks’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:816:in _run_initialize_callbacks' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/core.rb:348:in init_with’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/persistence.rb:71:in instantiate' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/querying.rb:52:in block (2 levels) in find_by_sql’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/result.rb:57:in block in each' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/result.rb:57:in each’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/result.rb:57:in each' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/querying.rb:52:in map’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/querying.rb:52:in block in find_by_sql' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications/instrumenter.rb:23:in instrument’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/querying.rb:51:in find_by_sql' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/relation.rb:560:in block in exec_queries’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/relation.rb:584:in skip_query_cache_if_necessary' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/relation.rb:547:in exec_queries’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/relation.rb:422:in load' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/relation.rb:200:in records’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/relation/delegation.rb:71:in each' /opt/zammad/app/controllers/channels_microsoft365_controller.rb:17:in index’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/basic_implicit_render.rb:6:in send_action' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/abstract_controller/base.rb:194:in process_action’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/rendering.rb:30:in process_action' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/abstract_controller/callbacks.rb:42:in block in process_action’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:109:in block in run_callbacks' /opt/zammad/app/controllers/application_controller/has_secure_content_security_policy_for_downloads.rb:18:in block (4 levels) in module:HasSecureContentSecurityPolicyForDownloads
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications.rb:180:in subscribed' /opt/zammad/app/controllers/application_controller/has_secure_content_security_policy_for_downloads.rb:17:in block (3 levels) in module:HasSecureContentSecurityPolicyForDownloads
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications.rb:180:in subscribed' /opt/zammad/app/controllers/application_controller/has_secure_content_security_policy_for_downloads.rb:16:in block (2 levels) in module:HasSecureContentSecurityPolicyForDownloads
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:118:in instance_exec' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:118:in block in run_callbacks’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:136:in run_callbacks' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/abstract_controller/callbacks.rb:41:in process_action’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/rescue.rb:22:in process_action' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/instrumentation.rb:34:in block in process_action’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications.rb:168:in block in instrument' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications/instrumenter.rb:23:in instrument’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/notifications.rb:168:in instrument' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/instrumentation.rb:32:in process_action’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal/params_wrapper.rb:256:in process_action' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.4.4/lib/active_record/railties/controller_runtime.rb:24:in process_action’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/abstract_controller/base.rb:134:in process' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionview-5.2.4.4/lib/action_view/rendering.rb:32:in process’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal.rb:191:in dispatch' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_controller/metal.rb:252:in dispatch’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/routing/route_set.rb:52:in dispatch' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/routing/route_set.rb:34:in serve’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/journey/router.rb:52:in block in serve' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/journey/router.rb:35:in each’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/journey/router.rb:35:in serve' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/routing/route_set.rb:840:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:420:in call_app!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-saml-1.10.1/lib/omniauth/strategies/saml.rb:89:in other_phase’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:190:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:192:in call!' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/strategy.rb:169:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/omniauth-1.9.1/lib/omniauth/builder.rb:45:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/etag.rb:27:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/conditional_get.rb:27:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/head.rb:12:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/http/content_security_policy.rb:18:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in context' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/cookies.rb:670:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/callbacks.rb:28:in block in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/callbacks.rb:98:in run_callbacks' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/callbacks.rb:26:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/debug_exceptions.rb:61:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/show_exceptions.rb:33:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/railties-5.2.4.4/lib/rails/rack/logger.rb:38:in call_app' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/railties-5.2.4.4/lib/rails/rack/logger.rb:26:in block in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/tagged_logging.rb:71:in block in tagged' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/tagged_logging.rb:28:in tagged’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/tagged_logging.rb:71:in tagged' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/railties-5.2.4.4/lib/rails/rack/logger.rb:26:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/remote_ip.rb:81:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/request_id.rb:27:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/method_override.rb:24:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/runtime.rb:22:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.4.4/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/executor.rb:14:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.4.4/lib/action_dispatch/middleware/static.rb:127:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/railties-5.2.4.4/lib/rails/engine.rb:524:in call' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/configuration.rb:227:in call’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/server.rb:706:in handle_request' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/server.rb:476:in process_client’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/server.rb:334:in block in run' /opt/zammad/vendor/bundle/ruby/2.6.0/gems/puma-3.12.6/lib/puma/thread_pool.rb:135:in block in spawn_thread’
/opt/zammad/vendor/bundle/ruby/2.6.0/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context’
I, [2020-11-18T09:35:21.183910 #29739-69963139157800] INFO – : Completed 500 Internal Server Error in 1069ms (Views: 0.2ms | ActiveRecord: 2.9ms)

Is there a way to force Zammad (from console or through deleting the old token somehwhere) to get a new grant?

There is no such way. You just need to delete all your channel accounts in Zammad, setup a new app within microsoft and need to add all channels again.

JFI: Here is the related issue https://github.com/zammad/zammad/issues/3292

1 Like

Update: Issue got fixed in the meantime (current 3.6 stable branch).

1 Like