Error when validating saml request for SP with unsigned requests
Sometimes the log shows the following error:
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: 2020-06-01 15:09:59 - NoMethodError - undefined method `gsub' for nil:NilClass:
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/saml_idp-0.8.0/lib/saml_idp/xml_security.rb:57:in `validate'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/saml_idp-0.8.0/lib/saml_idp.rb:74:in `valid_signature?'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/saml_idp-0.8.0/lib/saml_idp/service_provider.rb:26:in `valid_signature?'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/saml_idp-0.8.0/lib/saml_idp/request.rb:119:in `valid_signature?'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/saml_idp-0.8.0/lib/saml_idp/request.rb:98:in `valid?'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/lib/iapi/managers/saml_manager.rb:58:in `verify_request'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/lib/iapi/managers/saml_manager.rb:68:in `sp_info'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/lib/iapi/routes/auth.rb:149:in `block (2 levels) in <class:IApi>'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1635:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1635:in `block in compile!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:992:in `block (3 levels) in route!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1011:in `route_eval'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:992:in `block (2 levels) in route!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1040:in `block in process_route'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1038:in `catch'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1038:in `process_route'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:990:in `block in route!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:989:in `each'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:989:in `route!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1097:in `block in dispatch!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1076:in `block in invoke'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1076:in `catch'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1076:in `invoke'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1094:in `dispatch!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:924:in `block in call!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1076:in `block in invoke'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1076:in `catch'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1076:in `invoke'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:924:in `call!'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:913:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-protection-2.0.5/lib/rack/protection/xss_header.rb:18:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-protection-2.0.5/lib/rack/protection/path_traversal.rb:16:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-protection-2.0.5/lib/rack/protection/json_csrf.rb:26:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-protection-2.0.5/lib/rack/protection/base.rb:50:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-protection-2.0.5/lib/rack/protection/base.rb:50:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-protection-2.0.5/lib/rack/protection/frame_options.rb:31:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-2.0.7/lib/rack/logger.rb:15:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-2.0.7/lib/rack/common_logger.rb:33:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:231:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:224:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/rack-2.0.7/lib/rack/head.rb:12:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:194:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1957:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1502:in `block in call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1729:in `synchronize'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/sinatra-2.0.5/lib/sinatra/base.rb:1502:in `call'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:86:in `block in pre_process'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:84:in `catch'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:84:in `pre_process'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/thin-1.7.2/lib/thin/connection.rb:50:in `block in process'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: /usr/local/iapi/bundler/ruby/2.5.0/gems/eventmachine-1.2.7/lib/eventmachine.rb:1077:in `block in spawn_threadpool'
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: ERROR : Error: undefined method `gsub' for nil:NilClass
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: ERROR : Sending error to client: "undefined method `gsub' for nil:NilClass"
Looks like the saml request is invalid.
Is for:
Jun 01 15:09:59 immer12-8.glei.ch iapi[29878]: 0.0.0.0 - - [01/Jun/2020:15:09:59 +0200] "POST /auth/sp_info HTTP/1.1" 400 53 0.0108
Which seems to come from lib/iapi/managers/saml_manager.rb
(Line 58) - Which does not initialize service provider fingerprint if we allow unsigned requests.
Edited by mh