Very slow processing of attribute-filter.xml with many AttributeFilterPolicy elements

[Cantor, Scott]

On 11/28/14, 3:35 PM, "Lukas Hämmerle" <lukas.haemmerle at switch.ch> wrote:

>* Loading an attribute filter (e.g. at the start of the IdP) is not
>causing much delay with v3 but reloading a filter (and probably in
>particular unloading the old one/garbage collecting) is.

In what way? Is it tying up the system in any way? It's happening in a 
background thread and just swaps in at the end, or should be.


>a) Loading the IdP attribut filter (1.7 MByte, 6750 Rules):
>
>2014-11-28 08:45:14,238 - INFO
>[net.shibboleth.utilities.java.support.service.AbstractReloadableService:2
>45]
>- Service 'shibboleth.AttributeFilterService': Reloading service
>configuration
>2014-11-28 08:45:19,011 - INFO
>[net.shibboleth.ext.spring.service.ReloadableSpringService:382] -
>Service 'shibboleth.AttributeFilterService': Reload complete
>
>-> about 5s with v3

My best guess if it's that much faster than V2 is that Spring fixed 
something. Rod can comment eventually, but I don't think he fixed anything 
that revolutionary in the parsing code.

One thing is that unlike with metadata, we don't control what happens to 
the DOM at the end. I would *assume* the document is freed up by Spring, 
but we don't actually know that, and it could well be that it wasn't in 
the older Spring framework code.

>b) Reloading a "minimal" filter (5.3 KByte, 18 Rules):
>
>2014-11-28 08:50:13,948 - INFO
>[net.shibboleth.utilities.java.support.service.AbstractReloadableService:2
>45]
>- Service 'shibboleth.AttributeFilterService': Reloading service
>configuration
>2014-11-28 08:51:45,070 - INFO
>[net.shibboleth.ext.spring.service.ReloadableSpringService:382] -
>Service 'shibboleth.AttributeFilterService': Reload complete
>
>-> 91s with v3

I tend to wonder if that's more to do with the asynchrony involved, but 
I'll take a look at where those log messages are being written. I've 
certainly seen nothing like that myself in routine testing, particularly 
if I invoke the reload manually from the command line. It doesn't seem to 
pause like that. And I've been testing with my full OSU policy file, which 
is much larger than that, though nothing like your problem case.

-- Scott