Migration to 5.0 breaking LDAP and SAML login

Hi,

Zammad 4.1.x on Debian 10 here :slight_smile: Did an apt update, Zammad was updated to 5.0.

But then I couldn’t login anymore. Luckily, I did a VM snapshot first, so I reverted just before the update. I suspect the update is changing/breaking LDAP or SAML login.

I will create a local account to avoid being locked out, but since it’s an instance used “for real”, I won’t have a lot of time to fix it “live”.

Any idea or is it a known issue?

You provided so much information that we know all now.
Honestly - with above information, what do you expect now?

1 Like

Well, if it’s a known issue (eg LDAP/SAML are broken after upgrade) then it’s enough to me :slight_smile:

If it’s not, then I’ll try to find the root cause. That’s all I wanted to know.

edit: as I said “locked out”, it meant my credentials were rejected.

Same Problem here. We updated via debian apt and afterwards it was not possible to login via ldap. No error message.
Then i reinstalled zammad and i get he folowing output

root@fritz:/var/cache/apt/archives# apt-get install --reinstall zammad
Paketlisten werden gelesen... Fertig
Abhängigkeitsbaum wird aufgebaut.       
Statusinformationen werden eingelesen.... Fertig
0 aktualisiert, 0 neu installiert, 1 erneut installiert, 0 zu entfernen und 0 nicht aktualisiert.
Es mĂĽssen 287 MB an Archiven heruntergeladen werden.
Nach dieser Operation werden 0 B Plattenplatz zusätzlich benutzt.
Holen:1 https://dl.packager.io/srv/deb/zammad/zammad/stable/debian 10/main amd64 zammad amd64 5.0.0-1633402025.d288b48b.buster [287 MB]
Es wurden 287 MB in 9 s geholt (31,9 MB/s).                                                                                                
(Lese Datenbank ... 102958 Dateien und Verzeichnisse sind derzeit installiert.)
Vorbereitung zum Entpacken von .../zammad_5.0.0-1633402025.d288b48b.buster_amd64.deb ...
Entpacken von zammad (5.0.0-1633402025.d288b48b.buster) ĂĽber (5.0.0-1633402025.d288b48b.buster) ...
zammad (5.0.0-1633402025.d288b48b.buster) wird eingerichtet ...
# (Re)creating init scripts
Nothing to do.
Nothing to do.
Nothing to do.
# Enabling Zammad on boot
# Stopping Zammad
# database.yml found. Updating db...
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/version.rb:4: warning: already initialized constant Bundler::VERSION
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/version.rb:4: warning: previous definition of VERSION was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/constants.rb:4: warning: already initialized constant Bundler::WINDOWS
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/constants.rb:4: warning: previous definition of WINDOWS was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/constants.rb:5: warning: already initialized constant Bundler::FREEBSD
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/constants.rb:5: warning: previous definition of FREEBSD was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/constants.rb:6: warning: already initialized constant Bundler::NULL
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/constants.rb:6: warning: previous definition of NULL was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/rubygems_integration.rb:8: warning: already initialized constant Bundler::RubygemsIntegration::EXT_LOCK
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/rubygems_integration.rb:12: warning: previous definition of EXT_LOCK was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/current_ruby.rb:12: warning: already initialized constant Bundler::CurrentRuby::KNOWN_MINOR_VERSIONS
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/current_ruby.rb:12: warning: previous definition of KNOWN_MINOR_VERSIONS was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/current_ruby.rb:25: warning: already initialized constant Bundler::CurrentRuby::KNOWN_MAJOR_VERSIONS
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/current_ruby.rb:26: warning: previous definition of KNOWN_MAJOR_VERSIONS was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/current_ruby.rb:27: warning: already initialized constant Bundler::CurrentRuby::KNOWN_PLATFORMS
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/current_ruby.rb:28: warning: previous definition of KNOWN_PLATFORMS was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/vendor/fileutils/lib/fileutils.rb:105: warning: already initialized constant Bundler::FileUtils::VERSION
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/fileutils/lib/fileutils.rb:105: warning: previous definition of VERSION was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/vendor/fileutils/lib/fileutils.rb:1284: warning: already initialized constant Bundler::FileUtils::Entry_::S_IF_DOOR
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/fileutils/lib/fileutils.rb:1284: warning: previous definition of S_IF_DOOR was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/vendor/fileutils/lib/fileutils.rb:1568: warning: already initialized constant Bundler::FileUtils::Entry_::DIRECTORY_TERM
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/fileutils/lib/fileutils.rb:1568: warning: previous definition of DIRECTORY_TERM was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/vendor/fileutils/lib/fileutils.rb:1626: warning: already initialized constant Bundler::FileUtils::OPT_TABLE
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/fileutils/lib/fileutils.rb:1626: warning: previous definition of OPT_TABLE was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/vendor/fileutils/lib/fileutils.rb:1685: warning: already initialized constant Bundler::FileUtils::LOW_METHODS
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/fileutils/lib/fileutils.rb:1685: warning: previous definition of LOW_METHODS was here
/opt/zammad/vendor/ruby-2.7.4/lib/ruby/2.7.0/bundler/vendor/fileutils/lib/fileutils.rb:1692: warning: already initialized constant Bundler::FileUtils::METHODS
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/fileutils/lib/fileutils.rb:1692: warning: previous definition of METHODS was here
rake aborted!
ArgumentError: Trying to register Bundler::GemfileError for status code 4 but Bundler::GemfileError is already registered
/opt/zammad/config/boot.rb:5:in `require'
/opt/zammad/config/boot.rb:5:in `<top (required)>'
/opt/zammad/config/application.rb:3:in `require_relative'
/opt/zammad/config/application.rb:3:in `<top (required)>'
/opt/zammad/Rakefile:7:in `require_relative'
/opt/zammad/Rakefile:7:in `<top (required)>'
/opt/zammad/vendor/bundle/ruby/2.7.0/gems/rake-13.0.6/exe/rake:27:in `<top (required)>'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/cli/exec.rb:58:in `load'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/cli/exec.rb:58:in `kernel_load'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/cli/exec.rb:23:in `run'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/cli.rb:477:in `exec'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/cli.rb:31:in `dispatch'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/cli.rb:25:in `start'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/exe/bundle:49:in `block in <top (required)>'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/lib/bundler/friendly_errors.rb:128:in `with_friendly_errors'
/usr/local/rvm/gems/ruby-2.6.8/gems/bundler-2.2.26/exe/bundle:37:in `<top (required)>'
/opt/zammad/bin/bundle:5:in `load'
/opt/zammad/bin/bundle:5:in `<main>'
(See full trace by running task with --trace)
# Updating translations..
1 Like

You know the rules and so do I - provide your production log if you need help.

Please help me to understand at which part the documentation should be improved or why I should continue to write it:
https://docs.zammad.org/en/latest/install/update.html

I followed the doc instructions :slight_smile:

Updating with a local account available give me a red login alert (to rule out LDAP/SSO right now):

PG::NotNullViolation: ERREUR: une valeur NULL viole la contrainte NOT NULL de la colonne « activity<u>stream</u>type_id » DETAIL: La ligne en échec contient (22099, null, null, null, null, 42, 42, 2021-10-05 08:53:20.523, 2021-10-05 08:53:20.525)

It’s in French but in plain English it should be something like:

PG::NotNullViolation: ERROR: a NULL value violates the NOT NULL constraintof the row "activity<u>stream</u>type_id" DETAIL: The failing line contains (22099, null, null, null, null, 42, 42, 2021-10-05 08:53:20.523, 2021-10-05 08:53:20.525)

I also tried to:

    systemctl stop zammad
    zammad run rails Cache.clear
    zammad run rake db:migrate
    systemctl start zammad

After the initial update, but same result.

Hope this helps. On my side, I’ll just wait a bit (probably tonight) to get more logs while doing tests. I might also clone the VM to do it.

Sorry, I promise i will do better next time.
The relevant part of the production log is:
, [2021-10-05T10:54:57.972900 #2025-174280] INFO – : Processing by SessionsController#show as JSON
I, [2021-10-05T10:54:57.972955 #2025-174280] INFO – : Parameters: {“fingerprint”=>"-1840476201"}
E, [2021-10-05T10:54:57.992987 #2025-174280] ERROR – : PG::NotNullViolation: FEHLER: NULL-Wert in Spalte »activity_stream_type_id« verletz
t Not-Null-Constraint
DETAIL: Fehlgeschlagene Zeile enthält (52919, null, null, null, null, 622, 622, 2021-10-05 08:54:57.988244, 2021-10-05 08:54:57.991).
(ActiveRecord::NotNullViolation)
app/models/activity_stream.rb:82:in add' app/models/application_model/can_activity_stream_log.rb:46:in activity_stream_log’
app/controllers/sessions_controller.rb:228:in initiate_session_for' app/controllers/sessions_controller.rb:42:in show’
app/controllers/application_controller/has_download.rb:21:in block (4 levels) in <module:HasDownload>' app/controllers/application_controller/has_download.rb:20:in block (3 levels) in module:HasDownload’
app/controllers/application_controller/has_download.rb:19:in block (2 levels) in <module:HasDownload>' app/controllers/application_controller/handles_transitions.rb:16:in handle_transaction’
I, [2021-10-05T10:54:57.996424 #2025-174280] INFO – : Completed 422 Unprocessable Entity in 23ms (Views: 0.1ms | ActiveRecord: 3.6ms | All
ocations: 9800)

Hi @olivierlambert and @ado123 ,

can you try to run the following commands on your zammad run rails c to see what they return. Here an example of my dev system:

[1] pry(main)> TypeLookup.all
  TypeLookup Load (0.4ms)  SELECT "type_lookups".* FROM "type_lookups"
=> [#<TypeLookup:0x000055d043009768 id: 1, name: "session started", created_at: Mon, 04 Oct 2021 09:20:18 UTC +00:00, updated_at: Mon, 04 Oct 2021 09:20:18 UTC +00:00>,
 #<TypeLookup:0x000055d0430094c0 id: 2, name: "update", created_at: Mon, 04 Oct 2021 14:22:14 UTC +00:00, updated_at: Mon, 04 Oct 2021 14:22:14 UTC +00:00>,
 #<TypeLookup:0x000055d043009380 id: 3, name: "create", created_at: Mon, 04 Oct 2021 14:22:14 UTC +00:00, updated_at: Mon, 04 Oct 2021 14:22:14 UTC +00:00>]
[2] pry(main)> TypeLookup.by_name('update')
  TypeLookup Load (0.5ms)  SELECT "type_lookups".* FROM "type_lookups" WHERE "type_lookups"."name" = $1 LIMIT $2  [["name", "update"], ["LIMIT", 1]]
=> 2
[3] pry(main)> TypeLookup.by_name('create')
  TypeLookup Load (0.3ms)  SELECT "type_lookups".* FROM "type_lookups" WHERE "type_lookups"."name" = $1 LIMIT $2  [["name", "create"], ["LIMIT", 1]]
=> 3
[4] pry(main)> TypeLookup.by_name('session started')
  TypeLookup Load (0.6ms)  SELECT "type_lookups".* FROM "type_lookups" WHERE "type_lookups"."name" = $1 LIMIT $2  [["name", "session started"], ["LIMIT", 1]]
=> 1

Hi, is this what you wanted ?

Loading production environment (Rails 6.0.4.1)
2.7.0 :001 > TypeLookup.all
 => #<ActiveRecord::Relation [#<TypeLookup id: 1, name: "session started", created_at: "2017-10-06 13:49:50", updated_at: "2017-10-06 13:49:50">, #<TypeLookup id: 2, name: "create", created_at: "2017-10-06 14:24:58", updated_at: "2017-10-06 14:24:58">, #<TypeLookup id: 3, name: "update", created_at: "2017-10-06 14:25:00", updated_at: "2017-10-06 14:25:00">, #<TypeLookup id: 4, name: "reminder_reached", created_at: "2017-10-27 06:00:11", updated_at: "2017-10-27 06:00:11">, #<TypeLookup id: 5, name: "switch to", created_at: "2017-11-17 13:24:44", updated_at: "2017-11-17 13:24:44">, #<TypeLookup id: 6, name: "ended switch to", created_at: "2017-11-17 13:25:13", updated_at: "2017-11-17 13:25:13">]> 
2.7.0 :002 > TypeLookup.by_name('update')
 => 3 
2.7.0 :003 > TypeLookup.by_name('create')
 => 2 
2.7.0 :004 > TypeLookup.by_name('session started')
 => nil 
2.7.0 :005 > 

Hi @ado123 ,

weird it should return the id normally. Can you try to run Cache.clear again on your rails shell and try TypeLookup.by_name('session started') again? Does it really have no impact?

After clear this is the output

2.7.0 :002 > TypeLookup.by_name('session started')
 => 1 

can you login again?

Yes, now i could run apt-get install --reinstall zammad without error and everything seems to work.

I guess that was due to incorrect updating method.
Any way, I’m keen to learn how @olivierlambert instance is doing.

Okay let me try that :slight_smile: Back in few minutes to tell you the outcome :smiley:

So I did the steps but even with a apt-get install --reinstall zammad I got the:

Caused by:
PG::NotNullViolation: ERREUR:  une valeur NULL viole la contrainte NOT NULL de la colonne « activity_stream_type_id »
irb(main):001:0> TypeLookup.all
=> #<ActiveRecord::Relation [#<TypeLookup id: 1, name: "session started", created_at: "2020-12-15 10:39:04", updated_at: "2020-12-15 10:39:04">, #<TypeLookup id: 2, name: "create", created_at: "2020-12-15 10:43:39", updated_at: "2020-12-15 10:43:39">, #<TypeLookup id: 3, name: "update", created_at: "2020-12-15 10:43:39", updated_at: "2020-12-15 10:43:39">, #<TypeLookup id: 4, name: "switch to", created_at: "2020-12-15 10:50:27", updated_at: "2020-12-15 10:50:27">, #<TypeLookup id: 5, name: "ended switch to", created_at: "2020-12-15 10:50:54", updated_at: "2020-12-15 10:50:54">, #<TypeLookup id: 6, name: "escalation", created_at: "2020-12-15 13:50:47", updated_at: "2020-12-15 13:50:47">, #<TypeLookup id: 7, name: "escalation_warning", created_at: "2020-12-15 13:50:47", updated_at: "2020-12-15 13:50:47">, #<TypeLookup id: 8, name: "completed", created_at: "2021-02-10 21:24:33", updated_at: "2021-02-10 21:24:33">, #<TypeLookup id: 9, name: "reminder_reached", created_at: "2021-02-17 13:14:56", updated_at: "2021-02-17 13:14:56">]>
irb(main):002:0> TypeLookup.by_name('update')
=> nil
irb(main):003:0> TypeLookup.by_name('create')
=> 2
irb(main):004:0> TypeLookup.by_name('session started')
=> 1
irb(main):005:0> Cache.clear

However, after a BIG Cache.clear output, this time:

irb(main):006:0> TypeLookup.all
=> #<ActiveRecord::Relation [#<TypeLookup id: 1, name: "session started", created_at: "2020-12-15 10:39:04", updated_at: "2020-12-15 10:39:04">, #<TypeLookup id: 2, name: "create", created_at: "2020-12-15 10:43:39", updated_at: "2020-12-15 10:43:39">, #<TypeLookup id: 3, name: "update", created_at: "2020-12-15 10:43:39", updated_at: "2020-12-15 10:43:39">, #<TypeLookup id: 4, name: "switch to", created_at: "2020-12-15 10:50:27", updated_at: "2020-12-15 10:50:27">, #<TypeLookup id: 5, name: "ended switch to", created_at: "2020-12-15 10:50:54", updated_at: "2020-12-15 10:50:54">, #<TypeLookup id: 6, name: "escalation", created_at: "2020-12-15 13:50:47", updated_at: "2020-12-15 13:50:47">, #<TypeLookup id: 7, name: "escalation_warning", created_at: "2020-12-15 13:50:47", updated_at: "2020-12-15 13:50:47">, #<TypeLookup id: 8, name: "completed", created_at: "2021-02-10 21:24:33", updated_at: "2021-02-10 21:24:33">, #<TypeLookup id: 9, name: "reminder_reached", created_at: "2021-02-17 13:14:56", updated_at: "2021-02-17 13:14:56">]>
irb(main):007:0> TypeLookup.by_name('update')
=> 3
irb(main):008:0> TypeLookup.by_name('create')
=> 2
irb(main):009:0> TypeLookup.by_name('session started')
=> 1

Now it worked! Without reinstall, instantly. So clearly, Cache.clear in the CLI fixed it.

However, the Dashboard is broken (error in the browser console, like App.n(error) | executeSingel task: Dashboard ReferenceError: item is not defined).

Should I reboot?

@ado123 can you access the Dashboard?

I can’t access it:

App.n(error)                   | executeSingel task: Dashboard ReferenceError: item is not defined
    this.JST["app/views/dashboard/activity_stream_item"]/</< https://myURL.fr/assets/application-c89a4b0492e6b805dc3cd202300f32ff5748db169bff72b0b69f339bc31adba0.js:62
    this.JST["app/views/dashboard/activity_stream_item"]/< https://myURL.fr/assets/application-c89a4b0492e6b805dc3cd202300f32ff5748db169bff72b0b69f339bc31adba0.js:62
    "app/views/dashboard/activity_stream_item" https://myURL.fr/assets/application-c89a4b0492e6b805dc3cd202300f32ff5748db169bff72b0b69f339bc31adba0.js:62
    view https://myURL.fr/assets/application-c89a4b0492e6b805dc3cd202300f32ff5748db169bff72b0b69f339bc31adba0.js:22
    renderItem https://myURL.fr/assets/application-c89a4b0492e6b805dc3cd202300f32ff5748db169bff72b0b69f339bc31adba0.js:27
    s https://myURL.fr/assets/application-c89a4b0492e6b805dc3cd202300f32ff5748db169bff72b0b69f339bc31adba0.js:27
    renderAll https://myURL.fr/assets/application-c89a4b0492e6b805dc3cd202300f32ff5748db169bff72b0b69f339bc31adba0.js:27
    s https://myURL.fr/assets/
[...]

edit: SSO with SAML works, but not the LDAP login anymore. Internal user is OK

Okay got it WORKING!!!

I had to do the apt-get install --reinstall zammad after the Cache.clear otherwise the database migration wasn’t complete.

Thanks @ado123 @MrGeneration and @rolfschmidt