Checking SAML Config file per each backend request

[gabbydotCMS]

The following message appears in the SAML log file per backend request:

INFO filter.SamlAccessFilter: Error reading idpConfig for the site: xxxxx.xxxxxx.xxxxx

[jtesser]

After talking with Gabby we were thinking something of a miss cache might be missing here.

This way if a site doesn't have SAME configured that is also cached. OF course once configured it will need to be removed from the cache but that is what we mean by a miss cache.

[thstave]

Thanks for the feedback. Could you please provide a sample log containing the above error. Is this happening in all instances or a single installation? What IDP is being used?

[gabbydotCMS]

@thstave,

This happens on any instance where you deploy the plugin.

You don't even need to add a SAML Config. Just deploy the plugin, and you will see the messages popping up every time you click on any link on the backend; you will see the message multiple times depending on the request you do in the backend.

If you add a SAML Config (without even uploading an IdP metadata), and even if you make that config the default one, you will still see the message in the dotcms-saml.log file.

There's nothing else than those messages, so basically this is what you will see:

...
[30/07/18 22:22:31:650 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:650 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:653 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:658 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:666 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:668 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:669 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:849 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:957 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:967 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:975 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:982 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:31:990 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:006 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:015 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:025 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:038 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:076 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:086 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:096 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:096 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:142 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:155 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:32:158 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:623 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:691 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:692 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:693 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:696 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:696 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:696 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:856 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:875 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:880 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:953 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:38:969 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:41:355 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:41:384 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:41:524 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:41:618 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:41:627 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:55:795 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:55:810 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:55:818 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:58:650 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:58:856 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:58:953 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
[30/07/18 22:22:58:972 EDT]  INFO filter.SamlAccessFilter: Error reading idpConfig for the site: localhost
...

[thstave]

@gabbydotCMS ... While I'm not sure I understand the missed cache referenced earlier, I am able to duplicate the above entries. They are caused by a missing assets/saml/config.json file. While I'm not sure we should remove the log entry completely, we could change the logging from INFO to DEBUG which wouldn't clutter the log.
https://github.com/dotCMS/plugin-com.dotcms.dotsaml/blob/ethode-sp-endpoint-acs-rework/src/com/dotcms/plugin/saml/v3/filter/SamlAccessFilter.java#L174

[gabbydotCMS]

@thstave The assets/saml/config.json is the file where the SAML Configuration entries (all the data gathered by the SAML Config Portlet) is stored; it's not missing.

Cluttering the log is not really the concern. The concern is that we keep checking for a SAML Config (idpConfig) for a site (host) that has not been configured to use SAML authentication per each request. Not having a SAML Configuration is something that we should be caching as well, so that we can avoid asking once and again.

[gabbydotCMS]

From Tom (slack) on Aug/06:

I have an update that should address issue 109. What it does is flag when either no config.json file exists or has no records. If either of those conditions occurs, the plugin will not attempt to read the file again until a new IdP is added.

If this sounds like what you are looking for I can commit the change. Since it does affect how configuration data is processed, I did create a new branch based off of your 4.0-4.3.x branch. I know you asked that I make changes to 4.0-4.3.x, but I thought it wise to keep these separate. Please let me know if this is Ok.

[gabbydotCMS]

From Gabby (sclack) on Aug/06:

I don't think this is a solution for the problem we are having.
1 .. the file should always exist; it's created with no records when the plugin is deployed, and yes. it could be manually deleted, but that's a whole different problem

2 if the client hosts several sites, and they set site 1 to authenticate via SAML , you will still be checking for the SAML configuration assigned to the rest of the sites (per each request that goes through the filter) when they are not even using SAML authentication

the problem here is that when a request is processed, the filter goes to the SAML cache to find the SAML configuration, and when it does not find it there, it goes to the config file to try to get it from there, and that will happen for every single request because the plugin has no memory of the previous times it has tried to find a SAML config for that site that does not use SAML

so the solution should be to cache that result that indicates that a site is not associated to any SAML Config, so for the following requests, the filter will not try to find it; the filter (from the cache) will remember that site as one that does not need to check for SAML Configuration

whenever the user adds a site to a SAML config, in addition to associated to that SAML config in the cache, you should also make sure its non-SAML-site status gets removed

[gabbydotCMS]

From Tom (slack) on Aug/07:

We need to know whether the cache is empty because the file was empty or is it empty because we haven't read it yet. That is what we are using the flags for. To signal whether we have attempted to read the file or not.

You're right, while we do check each site as to whether it is configured for SAML or not. Currently if it a site is not found, we will attempt to re-read the configuration file. I have patched that but will need to do some more testing.

[gabbydotCMS]

From Tom (slack) on Aug/08:

I did commit a new branch ethode/bypass-if-no-configuration. This branch contains the changes that we have been discussing for issure #109. Please let me know if you would like me to commit it differently or any questions you may have. Thanks.

[gabbydotCMS]

@thstave ... Thanks !!!

I'll test it locally today and let you know our feedback.

[gabbydotCMS]

PR: #111