An attempt is made to reference a node in a context where it does not exist

[Andrew Petro]

Started seeing this in the production logs, looks like it's always on attempts to access a Portlet resource URL.
MyUW uses some resource URLs to provide JSON and even markup for uPortal-home to use in rendering widgets.

Anyone seen this before?

Looks like maybe DLM is trying to compute the user's layout on the way to rendering the portlet resource URL. 

Which is odd, because I'd have thought the user's layout was already figured out in the course of rendering the uPortal-home home page. 
That is, here, it's the benefit information widget (markup generated server-side out of a resource URL), but to know that the user had that widget on their homepage, in their layout, it would have already had to resolve the user's DLM layout, 
so why is it messing around with personal layout fragment (PLF) incorporation on the way to rendering this resource URL?

ERROR [ajp-nio-8009-exec-29] o.j.p.web.ExceptionLoggingFilter 2019-10-17 13:59:35,607 - uPortal: unhandled exception 'NOT_FOUND_ERR: An attempt is made to reference a node in a context where it does not exist.' for URL=/portal/p/university-staff-benefits-statement/max/benefitInformationWidget.resource.uP, user=vREDACTEDv , from IP=1REDACTED0
org.w3c.dom.DOMException: NOT_FOUND_ERR: An attempt is made to reference a node in a context where it does not exist.
	at com.sun.org.apache.xerces.internal.dom.ParentNode.internalRemoveChild(ParentNode.java:504) ~[na:1.8.0_222]
	at com.sun.org.apache.xerces.internal.dom.ParentNode.removeChild(ParentNode.java:484) ~[na:1.8.0_222]
	at org.jasig.portal.layout.dlm.PositionManager.adjustPositionSet(PositionManager.java:211) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PositionManager.evaluateAndApply(PositionManager.java:159) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PositionManager.applyPositions(PositionManager.java:143) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PLFIntegrator.applyChildChanges(PLFIntegrator.java:91) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PLFIntegrator.mergeFolder(PLFIntegrator.java:210) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PLFIntegrator.applyChildChanges(PLFIntegrator.java:78) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PLFIntegrator.mergeFolder(PLFIntegrator.java:210) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PLFIntegrator.applyChildChanges(PLFIntegrator.java:78) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PLFIntegrator.mergePLFintoILF(PLFIntegrator.java:62) ~[classes/:na]
	at org.jasig.portal.layout.dlm.RDBMDistributedLayoutStore.getCompositeLayout(RDBMDistributedLayoutStore.java:1352) ~[classes/:na]
	at org.jasig.portal.layout.dlm.RDBMDistributedLayoutStore._getUserLayout(RDBMDistributedLayoutStore.java:1183) ~[classes/:na]
	at org.jasig.portal.layout.dlm.RDBMDistributedLayoutStore.getUserLayout(RDBMDistributedLayoutStore.java:374) ~[classes/:na]
	at sun.reflect.GeneratedMethodAccessor439.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_222]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_222]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:198) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at com.sun.proxy.$Proxy546.getUserLayout(Unknown Source) ~[na:na]
        ...

[Andrew Petro]

Over-trimmed that stack trace. Below is another one.

Hypothesis: the key bit turns out to be

	at org.jasig.portal.layout.TransientUserLayoutManagerWrapper.getSubscribeId(TransientUserLayoutManagerWrapper.java:343) ~[classes/:na]

This is a request for a resource URL of a portlet by fname. The TransientUserLayoutManagerWrapper tries to check whether there's an existing subscribeId for that portlet in the layout and prefers to use that, falling back on instantiating a temporary portlet window only if it doesn't find one.

MyUW is calling that more and more concurrently, with widgets and notifications on the home page making callbacks for JSON and content out of resource URLs out of portlets addressed by fname.

So my working hypothesis is that DLM isn't threadsafe when accessed in this way, which was probably just fine in the olden days of rendering one portlet by fname at a time maximized, but is problematic when the browser concurrently requests a bunch of resource URLs addressing portlets by fname.

Here's an idea, though: aside from the bookmarks portlet, I don't think we're using *user-edited* portlet preferences in MyUW. We're using lots of portlet-preferences, but we're using them as if they were portlet-definition parameters, not something users can edit on a per-portlet-subscription basis.

So long as that's the case, there's no need for TransientUserLayoutManagerWrapper to be asking the underlying DLM whether these fnames are in the layout, so I can hack the wrapper to greatly reduce the concurrent requests down into DLM.

May try that to try to get these stack traces to stop happening before there's too much chance for DLM layout corruption or whatever bad thing happens from concurrent DLM requests of this kind...

ERROR [ajp-nio-8009-exec-30] o.j.p.web.ExceptionLoggingFilter 2019-10-17 14:34:00,509 - uPortal: unhandled exception 'NOT_FOUND_ERR: An attempt is made to reference a node in a context where it does not exist.' for URL=/portal/p/earnings-statement/max/listOfLinks.resource.uP, user=dREDACTEDg , from IP=1REDACTED1

org.w3c.dom.DOMException: NOT_FOUND_ERR: An attempt is made to reference a node in a context where it does not exist.
	at com.sun.org.apache.xerces.internal.dom.ParentNode.internalRemoveChild(ParentNode.java:504) ~[na:1.8.0_222]
	at com.sun.org.apache.xerces.internal.dom.ParentNode.removeChild(ParentNode.java:484) ~[na:1.8.0_222]
	at org.jasig.portal.layout.dlm.DeleteManager.applyAndUpdateDeleteSet(DeleteManager.java:93) ~[classes/:na]
	at org.jasig.portal.layout.dlm.PLFIntegrator.mergePLFintoILF(PLFIntegrator.java:51) ~[classes/:na]
	at org.jasig.portal.layout.dlm.RDBMDistributedLayoutStore.getCompositeLayout(RDBMDistributedLayoutStore.java:1352) ~[classes/:na]
	at org.jasig.portal.layout.dlm.RDBMDistributedLayoutStore._getUserLayout(RDBMDistributedLayoutStore.java:1183) ~[classes/:na]
	at org.jasig.portal.layout.dlm.RDBMDistributedLayoutStore.getUserLayout(RDBMDistributedLayoutStore.java:374) ~[classes/:na]
	at sun.reflect.GeneratedMethodAccessor516.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_222]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_222]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:198) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at com.sun.proxy.$Proxy510.getUserLayout(Unknown Source) ~[na:na]
	at org.jasig.portal.layout.dlm.DistributedLayoutManager.getDistributedUserLayout(DistributedLayoutManager.java:230) ~[classes/:na]
	at org.jasig.portal.layout.dlm.DistributedLayoutManager.getUserLayoutDOM(DistributedLayoutManager.java:217) ~[classes/:na]
	at org.jasig.portal.layout.dlm.DistributedLayoutManager.getSubscribeId(DistributedLayoutManager.java:1316) ~[classes/:na]
	at org.jasig.portal.layout.TransientUserLayoutManagerWrapper.getSubscribeId(TransientUserLayoutManagerWrapper.java:343) ~[classes/:na]
	at org.jasig.portal.portlet.registry.PortletEntityRegistryImpl.getOrCreatePortletEntityByFname(PortletEntityRegistryImpl.java:253) ~[classes/:na]
	at org.jasig.portal.portlet.registry.PortletWindowRegistryImpl.getOrCreateDefaultPortletWindowByFname(PortletWindowRegistryImpl.java:166) ~[classes/:na]
	at sun.reflect.GeneratedMethodAccessor433.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_222]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_222]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) ~[spring-aop-3.2.9.RELEASE.jar:3.2.9.RELEASE]
	at com.sun.proxy.$Proxy483.getOrCreateDefaultPortletWindowByFname(Unknown Source) ~[na:na]
	at org.jasig.portal.url.SingleTabUrlNodeSyntaxHelper.getPortletForFolderName(SingleTabUrlNodeSyntaxHelper.java:384) ~[classes/:na]
	at sun.reflect.GeneratedMethodAccessor413.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_222]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_222]

As ever,

Andrew

[Andrew Petro]

Here's the patch to stop checking for subscribed copies of portlets by fname, except for my-bookmarks

https://git.doit.wisc.edu/snippets/137

That should eliminate these concurrent requests in DLM, which is where the stack traces are indicating a problem.

Maybe much less of a big deal, but I'm pretty sure I don't think this is threadsafe either:

              IPortletDefinition chanDef = PortletDefinitionRegistryLocator.getPortletDefinitionRegistry().getPortletDefinitionByFname(fname);

                if(chanDef!=null) {

                    // assign a new id

                    subId = getNextSubscribeId();

                    mFnameMap.put(fname,subId);

                    mSubIdMap.put(subId,fname);

                    mChanMap.put(subId,chanDef);

                }

the individual maps are synchronized

    private Map<String, String> mFnameMap = Collections.synchronizedMap(new HashMap<String, String>());

but accessing them in series, seems like a couple threads could switch just wrong so that the maps become inconsistent. Suppose it's worth wrapping that in a synchronized?

That said, even if this remaining bit isn't technically threadsafe, it should be a really rare and low-consequence problem.

As ever,

Andrew

[Benito Gonzalez]

Thank you for your insights, Andrew!!

--bjagg

---

From: "'Andrew Petro' via uPortal Community" <uporta...@apereo.org>
To: "uPortal Community" <uporta...@apereo.org>
Sent: Friday, October 18, 2019 5:39:00 AM
Subject: [uportal-user] Re: An attempt is made to reference a node in a context where it does not exist

--
You received this message because you are subscribed to the Google Groups "uPortal Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to uportal-user...@apereo.org.
To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/uportal-user/69b59fa9-2531-486d-8c5c-1b41b7c6f376%40apereo.org.