long start = System.currentTimeMillis();
long elapsedTime = 0;
float startTotalMemory = ((float)Runtime.getRuntime().totalMemory() - Runtime.getRuntime().freeMemory());
DatabaseWrapper dbWrapper = new DatabaseWrapper(CastorDatabaseService.getDatabase());
beginTransaction(dbWrapper.getDatabase());
try
{
validateAndModifyInputParameters(dbWrapper.getDatabase());
this.nodeDeliveryController = NodeDeliveryController.getNodeDeliveryController(this.siteNodeId, this.languageId, this.contentId);
this.integrationDeliveryController = IntegrationDeliveryController.getIntegrationDeliveryController(this.siteNodeId, this.languageId, this.contentId);
boolean isUserRedirected = false;
Integer protectedSiteNodeVersionId = this.nodeDeliveryController.getProtectedSiteNodeVersionIdForPageCache(dbWrapper.getDatabase(), siteNodeId);
logger.info("protectedSiteNodeVersionId:" + protectedSiteNodeVersionId);
Integer forceProtocolChangeSetting = this.nodeDeliveryController.getForceProtocolChangeSettingForPageCache(dbWrapper.getDatabase(), siteNodeId);
//System.out.println("forceProtocolChangeSetting:" + forceProtocolChangeSetting);
if(logger.isInfoEnabled())
logger.info("protectedSiteNodeVersionId:" + protectedSiteNodeVersionId);
String protectWorking = CmsPropertyHandler.getProtectDeliverWorking();
String protectPreview = CmsPropertyHandler.getProtectDeliverPreview();
boolean protectDeliver = false;
if(protectWorking.equals("true") && CmsPropertyHandler.getOperatingMode().equals("0"))
protectDeliver = true;
else if(protectPreview.equals("true") && CmsPropertyHandler.getOperatingMode().equals("2"))
protectDeliver = true;
isUserRedirected = handleAccessBasedProtocolRedirect(protectedSiteNodeVersionId, this.repositoryId, forceProtocolChangeSetting, dbWrapper.getDatabase());
if(!isUserRedirected)
{
if(getRequest().getParameter("authenticateUser") != null && getRequest().getParameter("authenticateUser").equals("true"))
{
isUserRedirected = authenticateUser(dbWrapper.getDatabase());
}
}
if(!isUserRedirected)
{
if(logger.isInfoEnabled())
logger.info("RemoteAddress:" + getRequest().getRemoteAddr());
if(CmsPropertyHandler.getAllowInternalCallsBasedOnIP())
{
if(getRequest().getRemoteAddr().equals("127.0.0.1") || getRequest().getRemoteAddr().equals("192.168.0.1") || getRequest().getRemoteAddr().equals("0:0:0:0:0:0:0:1%0"))
protectDeliver = false;
}
boolean isAnonymousAuthorized = true;
logger.info("protectedSiteNodeVersionId:" +protectedSiteNodeVersionId);
if(protectedSiteNodeVersionId != null)
{
SiteNodeVersionVO siteNodeVersionVO = SiteNodeVersionController.getController().getSiteNodeVersionVOWithId(protectedSiteNodeVersionId, dbWrapper.getDatabase());
if(siteNodeVersionVO.getIsProtected().intValue() == SiteNodeVersionVO.YES_WITH_INHERIT_FALLBACK.intValue())
isAnonymousAuthorized = AccessRightController.getController().getIsPrincipalAuthorized(dbWrapper.getDatabase(), (InfoGluePrincipal)this.getAnonymousPrincipal(), "SiteNodeVersion.Read", protectedSiteNodeVersionId.toString(), false);
else
isAnonymousAuthorized = AccessRightController.getController().getIsPrincipalAuthorized(dbWrapper.getDatabase(), (InfoGluePrincipal)this.getAnonymousPrincipal(), "SiteNodeVersion.Read", protectedSiteNodeVersionId.toString());
}
logger.info("isAnonymousAuthorized:" + isAnonymousAuthorized);
logger.info("URI:" + getOriginalFullURL());
if((protectedSiteNodeVersionId != null && !isAnonymousAuthorized) || protectDeliver || getOriginalFullURL().indexOf("ticket=") > -1)
{
logger.info("Plain login routine which among others looks for ticket....");
if(logger.isInfoEnabled())
{
logger.info("protectedSiteNodeVersionId:" + protectedSiteNodeVersionId);
logger.info("protectDeliver:" + protectDeliver);
}
isUserRedirected = handleExtranetLogic(dbWrapper.getDatabase(), this.repositoryId, protectedSiteNodeVersionId, protectDeliver, false);
}
else
{
String forceIdentityCheck = RepositoryDeliveryController.getRepositoryDeliveryController().getExtraPropertyValue(this.repositoryId, "forceIdentityCheck");
if(logger.isInfoEnabled())
logger.info("forceIdentityCheck:" + forceIdentityCheck);
if(this.principal == null || CmsPropertyHandler.getAnonymousUser().equalsIgnoreCase(this.principal.getName()))
{
if(CmsPropertyHandler.getForceIdentityCheck().equalsIgnoreCase("true") || (forceIdentityCheck != null && forceIdentityCheck.equalsIgnoreCase("true")))
{
boolean isForcedIdentityCheckDisabled = this.nodeDeliveryController.getIsForcedIdentityCheckDisabled(dbWrapper.getDatabase(), this.siteNodeId);
if(!isForcedIdentityCheckDisabled && getHttpSession().getAttribute("ssoChecked") == null && (getRequest().getParameter("skipSSOCheck") == null || !getRequest().getParameter("skipSSOCheck").equals("true")))
{
Timer t = new Timer();
logger.info("Let's check for IP:s and user agents to skip redirect for...");
String userAgentsRegexp = CmsPropertyHandler.getUserAgentsSkippingSSOCheck();
String ipAddressesRegexp = CmsPropertyHandler.getIpNumbersSkippingSSOCheck();
logger.info("userAgentsRegexp:" + userAgentsRegexp);
if(userAgentsRegexp != null && !userAgentsRegexp.equals("") && getBrowserBean() != null && getBrowserBean().getUseragent() != null)
{
if(getBrowserBean().getUseragent().matches(userAgentsRegexp))
{
logger.info("Skipping SSO check for this useragent: " + getBrowserBean().getUseragent());
isForcedIdentityCheckDisabled = true;
}
}
logger.info("isForcedIdentityCheckDisabled:" + isForcedIdentityCheckDisabled);
if(!isForcedIdentityCheckDisabled)
{
logger.info("ipAddressesRegexp:" + ipAddressesRegexp);
if(ipAddressesRegexp != null && !ipAddressesRegexp.equals("") && getRequest().getRemoteAddr() != null)
{
logger.info("IP:" + getRequest().getRemoteAddr());
if(getRequest().getRemoteAddr().matches(ipAddressesRegexp))
{
logger.info("Skipping SSO check for this ip address: " + getRequest().getRemoteAddr());
isForcedIdentityCheckDisabled = true;
}
}
}
if(logger.isInfoEnabled())
logger.info("Checking ip and useragent took: " + t.getElapsedTime());
}
if(logger.isInfoEnabled())
{
logger.info("isForcedIdentityCheckDisabled:" + isForcedIdentityCheckDisabled);
logger.info("isForcedIdentityCheckDisabled:" + isForcedIdentityCheckDisabled);
logger.info("getHttpSession().getAttribute(ssoChecked):" + getHttpSession().getAttribute("ssoChecked"));
logger.info("getRequest().getParameter(skipSSOCheck):" + getRequest().getParameter("skipSSOCheck"));
}
if(!isForcedIdentityCheckDisabled && getHttpSession().getAttribute("ssoChecked") == null && (getRequest().getParameter("skipSSOCheck") == null || !getRequest().getParameter("skipSSOCheck").equals("true")))
{
isUserRedirected = handleExtranetLogic(dbWrapper.getDatabase(), true);
logger.info("isUserRedirected:" + isUserRedirected);
}
else if(!isForcedIdentityCheckDisabled && getRequest().getParameter("skipSSOCheck") != null && getRequest().getParameter("skipSSOCheck").equals("true"))
{
getHttpSession().setAttribute("ssoChecked", "true");
}
}
}
}
}
logger.info("isUserRedirected:" + isUserRedirected);
logger.info("principal:" + this.principal);
if(!isUserRedirected)
isUserRedirected = rewriteUrl();
String pageKey = this.nodeDeliveryController.getPageCacheKey(dbWrapper.getDatabase(), this.getHttpSession(), getRequest(), this.siteNodeId, this.languageId, this.contentId, browserBean.getUseragent(), this.getRequest().getQueryString(), "");
if(logger.isInfoEnabled())
logger.info("pageKey:" + pageKey);
templateController = getTemplateController(dbWrapper, getSiteNodeId(), getLanguageId(), getContentId(), getRequest(), (InfoGluePrincipal)this.principal, false);
if(logger.isInfoEnabled())
logger.info("handled extranet users: " + isUserRedirected);
// ----
// -- portlet
// ----
// -- check if the portal is active
String portalEnabled = CmsPropertyHandler.getEnablePortal();
boolean portalActive = ((portalEnabled != null) && portalEnabled.equals("true"));
if (portalActive && !isRecacheCall)
{
if(logger.isInfoEnabled())
logger.info("---> Checking for portlet action");
PortalService service = new PortalService();
//TODO: catch PortalException?
boolean actionExecuted = service.service(getRequest(), getResponse());
// -- if an action was executed return NONE as a redirect is issued
if (actionExecuted)
{
if(logger.isInfoEnabled())
logger.info("---> PortletAction was executed, returning NONE as a redirect has been issued");
isUserRedirected = true;
return NONE;
}
}
if(logger.isInfoEnabled())
logger.info("handled portal action: " + isUserRedirected);
if(!isUserRedirected)
{
if(logger.isInfoEnabled())
logger.info("this.templateController.getPrincipal():" + templateController.getPrincipal());
DeliveryContext deliveryContext = DeliveryContext.getDeliveryContext(true);
deliveryContext.setRepositoryName(this.repositoryName);
deliveryContext.setSiteNodeId(this.siteNodeId);
deliveryContext.setContentId(this.contentId);
deliveryContext.setLanguageId(this.languageId);
deliveryContext.setPageKey(pageKey);
//deliveryContext.setSession(this.getSession());
//deliveryContext.setInfoGlueAbstractAction(this);
deliveryContext.setHttpServletRequest(this.getRequest());
deliveryContext.setHttpServletResponse(this.getResponse());
deliveryContext.setUseFullUrl(Boolean.parseBoolean(CmsPropertyHandler.getUseDNSNameInURI()));
boolean enableIfModifiedHeaders = CmsPropertyHandler.getEnableIfModifiedHeaders();
boolean skipRender = false;
PageDeliveryMetaDataVO pdmd = null;
if (enableIfModifiedHeaders) {
try
{
boolean isIfModifiedLogic = getIsIfModifiedLogicValid(deliveryContext, templateController.getPrincipal(), true);
logger.info("enableIfModifiedHeaders state is:" + enableIfModifiedHeaders);
if(isIfModifiedLogic)
{
String ifModifiedSince = this.getRequest().getHeader("If-Modified-Since");
logger.info("ifModifiedSince:" + ifModifiedSince);
//System.out.println("pageKey:" + pageKey);
if(ifModifiedSince != null && !ifModifiedSince.equals(""))
{
pdmd = PageDeliveryMetaDataController.getController().getPageDeliveryMetaDataVO(dbWrapper.getDatabase(), this.siteNodeId, this.languageId, this.contentId);
logger.info("pdmd A:" + (pdmd == null ? "null" : pdmd.getId()));
if(pdmd != null && pdmd.getLastModifiedDateTime() != null)
{
logger.info("pdmd getLastModifiedTimeout:" + pdmd.getLastModifiedTimeout());
logger.info("System.currentTimeMillis:" + System.currentTimeMillis());
long diff = System.currentTimeMillis() - (pdmd.getLastModifiedTimeout() != null ? pdmd.getLastModifiedTimeout().getTime() : 0);
logger.info("diff:" + diff);
if(diff < 0 || pdmd.getLastModifiedTimeout() == null)
{
Date ifModifiedSinceDate = HTTP_DATE_FORMAT.parse( ifModifiedSince );
logger.info("pdmd B:" + pdmd.getId() + ":" + pdmd.getLastModifiedDateTime());
logger.info("*************\nCompares:" + pdmd.getLastModifiedDateTime() + "=" + ifModifiedSinceDate);
logger.info("pdmd.getLastModifiedTimeout():" + pdmd.getLastModifiedTimeout());
if(ifModifiedSinceDate.getTime() >= pdmd.getLastModifiedDateTime().getTime() - 1000)
{
logger.info("Returning NOT_MODIFIED");
this.getResponse().setStatus( HttpServletResponse.SC_NOT_MODIFIED );
pageTimer.printElapsedTime("Delivered NOT MODIFIED IN", 50);
skipRender = true;
return NONE;
}
}
}
}
}
}
catch (Exception e)
{
e.printStackTrace();
}
}
logger.info("skipRender:" + skipRender);
if(!skipRender)
{
SiteNodeTypeDefinitionVO siteNodeTypeDefinitionVO = getSiteNodeTypeDefinition(this.siteNodeId, dbWrapper.getDatabase());
try
{
String invokerClassName = siteNodeTypeDefinitionVO.getInvokerClassName();
PageInvoker pageInvoker = (PageInvoker)Class.forName(invokerClassName).newInstance();
pageInvoker.setParameters(dbWrapper, this.getRequest(), this.getResponse(), templateController, deliveryContext);
pageInvoker.deliverPage();
boolean isCachedResponse = deliveryContext.getIsCachedResponse();
logger.info("isCachedResponse:" + isCachedResponse);
boolean isIfModifiedLogic = getIsIfModifiedLogicValid(deliveryContext, templateController.getPrincipal(), false);
logger.info("isIfModifiedLogic 2:" + isIfModifiedLogic);
logger.info("deliveryContext.getLastModifiedDateTime():" + deliveryContext.getLastModifiedDateTime());
/*Fetching meta info data*/
if(isCachedResponse && pdmd == null && isIfModifiedLogic && enableIfModifiedHeaders) {
logger.info("enableIfModifiedHeaders state is:" + enableIfModifiedHeaders);
pdmd = PageDeliveryMetaDataController.getController().getPageDeliveryMetaDataVO(dbWrapper.getDatabase(), this.siteNodeId, this.languageId, this.contentId);
}
if(pdmd != null)
logger.info("pdmd():" + pdmd.getLastModifiedDateTime());
if(isIfModifiedLogic && (!isCachedResponse || pdmd == null/* || deliveryContext.getLastModifiedDateTime().after(pdmd.getLastModifiedDateTime())*/))
{
Timer t2 = new Timer();
logger.info("We should register the last modified date now. Add it to the thread which registers it: " + deliveryContext.getLastModifiedDateTime() + ":" + deliveryContext.hashCode());
try
{
PageDeliveryMetaDataVO pageDeliveryMetaDataVO = new PageDeliveryMetaDataVO();
List<String> entities = deliveryContext.getAllUsedEntitiesAsSet();
List<String> allUsedEntitiesFilteredCopy = new ArrayList<String>();
for(String s : entities)
{
if(s.startsWith("content_") && s.indexOf("_", 8) == -1)
{
allUsedEntitiesFilteredCopy.add(s.replaceAll("content_", "c_"));
//allUsedEntitiesFilteredCopy.add(s); //getPooledString(s.hashCode()));
//System.out.println("Added: " + s);
}
else if(s.startsWith("siteNode_"))
allUsedEntitiesFilteredCopy.add(s.replaceAll("siteNode_", "sn_"));
else if(s.startsWith("selectiveCacheUpdateNonApplicable"))
{
allUsedEntitiesFilteredCopy.clear();
allUsedEntitiesFilteredCopy.add(s);
pageDeliveryMetaDataVO.setSelectiveCacheUpdateNotApplicable(true);
}
}
Collection<PageDeliveryMetaDataEntityVO> entitiesCollection = new ArrayList<PageDeliveryMetaDataEntityVO>();
for(String s : allUsedEntitiesFilteredCopy)
{
if(s.startsWith("c_"))
{
PageDeliveryMetaDataEntityVO pageDeliveryMetaDataEntityVO = new PageDeliveryMetaDataEntityVO();
pageDeliveryMetaDataEntityVO.setContentId(new Integer(s.replaceAll("c_", "")));
pageDeliveryMetaDataEntityVO.setPageDeliveryMetaDataId(pageDeliveryMetaDataVO.getId());
entitiesCollection.add(pageDeliveryMetaDataEntityVO);
}
else if(s.startsWith("sn_"))
{
PageDeliveryMetaDataEntityVO pageDeliveryMetaDataEntityVO = new PageDeliveryMetaDataEntityVO();
pageDeliveryMetaDataEntityVO.setSiteNodeId(new Integer(s.replaceAll("sn_", "")));
pageDeliveryMetaDataEntityVO.setPageDeliveryMetaDataId(pageDeliveryMetaDataVO.getId());
entitiesCollection.add(pageDeliveryMetaDataEntityVO);
}
}
String allUsedEntitiesAsString = StringUtils.join(allUsedEntitiesFilteredCopy, "|");
logger.info("allUsedEntitiesAsString:" + allUsedEntitiesAsString);
//System.out.println("allUsedEntitiesAsString:" + allUsedEntitiesAsString.length());
pageDeliveryMetaDataVO.setSiteNodeId(deliveryContext.getSiteNodeId());
pageDeliveryMetaDataVO.setLanguageId(deliveryContext.getLanguageId());
pageDeliveryMetaDataVO.setContentId(deliveryContext.getContentId());
pageDeliveryMetaDataVO.setLastModifiedDateTime(deliveryContext.getLastModifiedDateTime());
if(deliveryContext.getPageCacheTimeout() != null && deliveryContext.getPageCacheTimeout() > -1)
{
logger.info("deliveryContext.getPageCacheTimeout(): " + deliveryContext.getPageCacheTimeout());
logger.info("Setting page timeout: " + deliveryContext.getPageCacheTimeout()*1000);
logger.info("Current time: " + System.currentTimeMillis());
Calendar cal = Calendar.getInstance();
cal.add(Calendar.SECOND, deliveryContext.getPageCacheTimeout());
pageDeliveryMetaDataVO.setLastModifiedTimeout(cal.getTime());
}
else
logger.info("AAAAAAAAAAAAAAAAAAAAA: " + deliveryContext.getPageCacheTimeout());
pageDeliveryMetaDataVO.setUsedEntities(allUsedEntitiesAsString);
if (enableIfModifiedHeaders) {
PageDeliveryMetaDataController.getController().deletePageDeliveryMetaData(dbWrapper.getDatabase(), pageDeliveryMetaDataVO.getSiteNodeId(), null);
PageDeliveryMetaDataController.getController().create(dbWrapper.getDatabase(), pageDeliveryMetaDataVO, entitiesCollection);
}
String key = "" + pageDeliveryMetaDataVO.getSiteNodeId() + "_" + pageDeliveryMetaDataVO.getLanguageId() + "_" + pageDeliveryMetaDataVO.getContentId();
logger.info("key on store:" + key);
CacheController.cacheObjectInAdvancedCache("pageDeliveryMetaDataCache", key, pageDeliveryMetaDataVO);
}
catch (Exception e)
{
logger.error("Error storing page meta data: " + e.getMessage(), e);
}
t2.printElapsedTime("AAAAAAAAAAAAAAAAA",20);
}
request.setAttribute("progress", "after pageInvoker was called");
}
catch(ClassNotFoundException e)
{
throw new SystemException("An error was thrown when trying to use the page invoker class assigned to this page type:" + e.getMessage(), e);
}
finally
{
deliveryContext.clear();
deliveryContext = null;
}
}
}
//StatisticsService.getStatisticsService().registerRequest(getRequest(), getResponse(), pagePath, elapsedTime);
//logger.info("Registered request in statistics service");
}
catch(PageNotFoundException e)
{
String extraInformation = "Original URL: " + getOriginalFullURL() + "\n";
extraInformation += "Referer: " + getRequest().getHeader("Referer") + "\n";
extraInformation += "UserAgent: " + getRequest().getHeader("User-Agent") + "\n";
extraInformation += "User IP: " + getRequest().getRemoteAddr();
logger.warn("A user requested a non existing page:" + e.getMessage() + "\n" + extraInformation);
rollbackTransaction(dbWrapper.getDatabase());
getResponse().setContentType("text/html; charset=UTF-8");
getRequest().setAttribute("responseCode", "404");
getRequest().setAttribute("error", e);
getRequest().setAttribute("errorUrl", getErrorUrl());
getRequest().getRequestDispatcher("/ErrorPage.action").forward(getRequest(), getResponse());
}
catch(PageNotPublishedException e)
{
String extraInformation = "Original URL: " + getOriginalFullURL() + "\n";
extraInformation += "Referer: " + getRequest().getHeader("Referer") + "\n";
extraInformation += "UserAgent: " + getRequest().getHeader("User-Agent") + "\n";
extraInformation += "User IP: " + getRequest().getRemoteAddr();
logger.info("A user requested page which has no published version:" + e.getMessage() + "\n" + extraInformation);
rollbackTransaction(dbWrapper.getDatabase());
getResponse().setContentType("text/html; charset=UTF-8");
getRequest().setAttribute("responseCode", "404");
getRequest().setAttribute("error", e);
getRequest().setAttribute("errorUrl", getErrorUrl());
getRequest().setAttribute("originalFullURL", getOriginalFullURL());
getRequest().getRequestDispatcher("/ErrorPage.action").forward(getRequest(), getResponse());
}
catch(NoBaseTemplateFoundException e)
{
String extraInformation = "Original URL: " + getOriginalFullURL() + "\n";
extraInformation += "Referer: " + getRequest().getHeader("Referer") + "\n";
extraInformation += "UserAgent: " + getRequest().getHeader("User-Agent") + "\n";
extraInformation += "User IP: " + getRequest().getRemoteAddr();
logger.error("A user requested a page which had no base template (probably of the old HTMLPageInvoker type - should be changed):" + e.getMessage() + "\n" + extraInformation);
rollbackTransaction(dbWrapper.getDatabase());
getResponse().setContentType("text/html; charset=UTF-8");
getRequest().setAttribute("responseCode", "500");
getRequest().setAttribute("error", e);
getRequest().setAttribute("errorUrl", getErrorUrl());
getRequest().getRequestDispatcher("/ErrorPage.action").forward(getRequest(), getResponse());
}
catch(IOException e)
{
String extraInformation = "Original URL: " + getOriginalFullURL() + "\n";
extraInformation += "Referer: " + getRequest().getHeader("Referer") + "\n";
extraInformation += "UserAgent: " + getRequest().getHeader("User-Agent") + "\n";
extraInformation += "User IP: " + getRequest().getRemoteAddr();
if(e.getCause() != null)
{
if(e.getCause() instanceof SocketException)
logger.warn("A io exception was thrown returning data to client:" + e.getCause().getMessage() + "\n" + extraInformation);
else
logger.error("A io exception was thrown returning data to client:" + e.getCause().getMessage() + "\n" + extraInformation);
}
else
logger.error("A io exception was thrown returning data to client:" + e.getMessage() + "\n" + extraInformation);
rollbackTransaction(dbWrapper.getDatabase());
}
catch(Exception e)
{
logger.warn("Extra warn:" + e.getMessage(), e);
String extraInformation = "Original URL: " + getOriginalFullURL() + "\n";
extraInformation += "Referer: " + getRequest().getHeader("Referer") + "\n";
extraInformation += "UserAgent: " + getRequest().getHeader("User-Agent") + "\n";
extraInformation += "User IP: " + getRequest().getRemoteAddr();
logger.error("An error occurred (se warning log for further info):" + e.getMessage());
logger.warn("An error occurred so we should not complete the transaction:" + e.getMessage() + "\n" + extraInformation, e);
rollbackTransaction(dbWrapper.getDatabase());
getResponse().setContentType("text/html; charset=UTF-8");
getRequest().setAttribute("responseCode", "500");
getRequest().setAttribute("error", e);
getRequest().setAttribute("errorUrl", getErrorUrl());
getRequest().getRequestDispatcher("/ErrorPage.action").forward(getRequest(), getResponse());
}
finally
{
if(logger.isInfoEnabled())
logger.info("Before closing transaction");
try
{
closeTransaction(dbWrapper.getDatabase());
}
catch(Exception e)
{
logger.error("Problem closing connection:" + e.getMessage(), e);
}