Skip to content

Commit

Permalink
logs: add more debug logging to help identify customers 404. ref: #30000
Browse files Browse the repository at this point in the history 
 (#30117)

We have noticed that customers are encountering intermittent 404 errors.
This information will be instrumental in pinpointing and addressing the
root cause of these errors.
  • Loading branch information
@erickgonzalez
erickgonzalez authored Sep 23, 2024
1 parent 462828c commit 477606b
Show file tree
Hide file tree
Showing 9 changed files with 225 additions and 111 deletions.
37 changes: 25 additions & 12 deletions dotCMS/src/main/java/com/dotcms/rendering/velocity/servlet/VelocityServlet.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
import com.dotmarketing.filters.Constants;
import com.dotmarketing.portlets.htmlpageasset.business.render.HTMLPageAssetNotFoundException;
import com.dotmarketing.portlets.htmlpageasset.business.render.HTMLPageAssetRenderedAPI;
import com.dotmarketing.portlets.htmlpageasset.business.render.PageContext;
import com.dotmarketing.portlets.htmlpageasset.business.render.PageContextBuilder;
import com.dotmarketing.util.Logger;
import com.dotmarketing.util.LoginMode;
Expand Down Expand Up @@ -61,6 +62,7 @@ public VelocityServlet() {
public static PageMode processPageMode (final User user, final HttpServletRequest request) {

final LoginMode loginMode = LoginMode.get(request);
Logger.debug(VelocityServlet.class, "VelocityServlet_processPageMode LoginMode: " + loginMode.toString());

if (LoginMode.UNKNOWN == loginMode) {

Expand Down Expand Up @@ -100,22 +102,29 @@ private static boolean useNavigateMode(final HttpServletRequest request, LoginMo
@Override
@CloseDB
protected final void service(HttpServletRequest req, HttpServletResponse response) throws ServletException, IOException {
Logger.debug(this, "======Starting VelocityServlet_service=====");
final VelocityRequestWrapper request =VelocityRequestWrapper.wrapVelocityRequest(req);
final String uri = CMSUrlUtil.getCurrentURI(request);
HttpServletRequestThreadLocal.INSTANCE.setRequest(request);
HttpServletResponseThreadLocal.INSTANCE.setResponse(response);

Logger.debug(this, "VelocityServlet_service Uri: " + uri);

final User user = (userApi.getLoggedInUser(request)!=null)
? userApi.getLoggedInUser(request)
: userApi.getLoggedInFrontendUser(request) !=null
? userApi.getLoggedInFrontendUser(request)
: userApi.getAnonymousUserNoThrow();

? userApi.getLoggedInUser(request)
: userApi.getLoggedInFrontendUser(request) !=null
? userApi.getLoggedInFrontendUser(request)
: userApi.getAnonymousUserNoThrow();

Logger.debug(this, "VelocityServlet_service User " + user.toString());

request.setRequestUri(uri);
final PageMode mode = processPageMode(user, request);
Logger.debug(this, "VelocityServlet_service Pagemode: " + mode.toString());

// if you are hitting the servlet without running through the other filters
if (uri == null) {
Logger.debug(this, "VelocityServlet_service uri is null");
response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR, "VelocityServlet called without running through the CMS Filter");
Logger.error(this.getClass(),
"You cannot call the VelocityServlet without passing the requested url via a requestAttribute called "
Expand All @@ -125,8 +134,9 @@ protected final void service(HttpServletRequest req, HttpServletResponse respons

// if you are not running ee
if ((DbConnectionFactory.isMsSql() && LicenseUtil.getLevel() < LicenseLevel.PROFESSIONAL.level)
|| (DbConnectionFactory.isOracle() && LicenseUtil.getLevel() < LicenseLevel.PRIME.level)
|| (!LicenseUtil.isASAllowed())) {
|| (DbConnectionFactory.isOracle() && LicenseUtil.getLevel() < LicenseLevel.PRIME.level)
|| (!LicenseUtil.isASAllowed())) {
Logger.debug(this, "VelocityServlet_service Enterprise License is required");
Logger.error(this, "Enterprise License is required");
response.sendError(HttpServletResponse.SC_NOT_FOUND);
return;
Expand All @@ -135,15 +145,18 @@ protected final void service(HttpServletRequest req, HttpServletResponse respons

// try to get the page
try {
final PageContext pageContextBuild = PageContextBuilder.builder()
.setPageUri(uri)
.setUser(user)
.setPageMode(mode)
.build();
Logger.debug(this, "VelocityServlet_service PageContext: " + pageContextBuild.toString());
final String pageHtml = htmlPageAssetRenderedAPI.getPageHtml(
PageContextBuilder.builder()
.setPageUri(uri)
.setUser(user)
.setPageMode(mode)
.build(),
pageContextBuild,
request,
response
);
Logger.debug(this, "VelocityServlet_service pageHtml: " + pageHtml);
response.getOutputStream().write(pageHtml.getBytes());
} catch (ResourceNotFoundException rnfe) {
Logger.warnAndDebug(this.getClass(), "ResourceNotFoundException" + rnfe.toString(), rnfe);
Expand Down
6 changes: 5 additions & 1 deletion dotCMS/src/main/java/com/dotmarketing/business/IdentifierFactoryImpl.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,11 @@ protected void updateIdentifierURI(Versionable webasset, Folder folder) throws D
* @return
*/
private Identifier check404(Identifier value) {
return value!=null && value.getAssetType()!=null && value.getAssetType().equals(IdentifierAPI.IDENT404) ? new Identifier() : value;
final boolean is404 = value!=null && value.getAssetType()!=null && value.getAssetType().equals(IdentifierAPI.IDENT404);
if(is404){
Logger.debug(this, "404 Identifier found: " + value.toString());
}
return is404 ? new Identifier() : value;
}

/**
Expand Down
1 change: 1 addition & 0 deletions dotCMS/src/main/java/com/dotmarketing/business/VersionableFactoryImpl.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -346,6 +346,7 @@ public Optional<ContentletVersionInfo> getContentletVersionInfo(

ContentletVersionInfo contentVersionInfo = this.icache.getContentVersionInfo(identifier, lang, variantName);
if(contentVersionInfo!=null && fourOhFour.equals(contentVersionInfo.getWorkingInode())) {
Logger.debug(this, "404 ContentletVersionInfo found for id: " + identifier + " lang: " + lang + " variant: " + variantName);
return Optional.empty();
}else if(contentVersionInfo!=null ){
return Optional.of(contentVersionInfo);
Expand Down
35 changes: 26 additions & 9 deletions dotCMS/src/main/java/com/dotmarketing/filters/CMSFilter.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,13 +10,11 @@
import com.dotmarketing.business.APILocator;
import com.dotmarketing.business.web.WebAPILocator;
import com.dotmarketing.db.DbConnectionFactory;
import com.dotmarketing.exception.DotDataException;
import com.dotmarketing.portlets.rules.business.RulesEngine;
import com.dotmarketing.portlets.rules.model.Rule;
import com.dotmarketing.util.*;
import io.vavr.Tuple2;
import io.vavr.control.Try;
import org.apache.commons.logging.LogFactory;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
Expand Down Expand Up @@ -90,8 +88,11 @@ private void doFilterInternal(ServletRequest req, ServletResponse res, FilterCha
String uri = urlUtil.getURIFromRequest(request);
String queryString = urlUtil.getURLQueryStringFromRequest(request);

Logger.debug(this.getClass(), "------CMSFilter----- Starting for Uri: " + uri);
Logger.debug(this.getClass(), "CMSFilter site = " + site.getIdentifier());
Logger.debug(this.getClass(), "CMSFilter Lang = " + languageId);
Logger.debug(this.getClass(), "CMSFilter queryString = " + queryString);

Logger.debug(this.getClass(), "CMS Filter URI = " + uri);

/*
* If someone is trying to go right to an asset without going through the cms, give them a
Expand All @@ -106,41 +107,53 @@ private void doFilterInternal(ServletRequest req, ServletResponse res, FilterCha
final Tuple2<IAm,IAmSubType> iAm =
this.urlUtil.resolveResourceType(IAm.NOTHING_IN_THE_CMS, uri, site, languageId);

Logger.debug(this.getClass(), "CMSFilter iAm = " + iAm);

// if I am a folder without a slash
if (iAm._1() == IAm.FOLDER && !uri.endsWith("/")) {
Logger.debug(this.getClass(), "CMSFilter iAm Folder without slash");
response.setHeader("Location", UtilMethods.isSet(queryString) ? uri + "/?" + queryString : uri + "/");
Try.run(()->response.setStatus(301));
return;
}

// if I am a Page with a trailing slash
if (iAm._1() == IAm.PAGE && iAm._2() == IAmSubType.PAGE_INDEX && uri.endsWith("/")) {
Logger.debug(this.getClass(), "CMSFilter iAm Index_Page");
uri = uri + CMS_INDEX_PAGE;
}


if (iAm._1() == IAm.PAGE) {
Logger.debug(this.getClass(), "CMSFilter iAm Page");
countPageVisit(request);
countSiteVisit(request, response);
final String uriWithoutQueryString = this.urlUtil.getUriWithoutQueryString(uri);
Logger.debug(this.getClass(), "CMSFilter uriWithoutQueryString = " + uriWithoutQueryString);
request.setAttribute(Constants.CMS_FILTER_URI_OVERRIDE,
this.urlUtil.getUriWithoutQueryString(uri));
queryString = (null == queryString)?
this.urlUtil.getQueryStringFromUri (uri):queryString;
uriWithoutQueryString);
final String queryStringFromUri = this.urlUtil.getQueryStringFromUri(uri);
Logger.debug(this.getClass(), "CMSFilter queryStringFromUri = " + queryStringFromUri);
queryString = (null == queryString) ? queryStringFromUri : queryString;
}

if (iAm._1() == IAm.FILE) {
Logger.debug(this.getClass(), "CMSFilter iAm File");
Identifier ident;
try {
// Serving the file through the /dotAsset servlet
StringWriter forward = new StringWriter();
forward.append("/dotAsset/");

Logger.debug(this.getClass(), "CMSFilter URI = " + uri);
Logger.debug(this.getClass(), "CMSFilter site = " + site.getIdentifier());
Logger.debug(this.getClass(), "CMSFilter Lang = " + languageId);
ident = APILocator.getIdentifierAPI().find(site, uri);
Logger.debug(this.getClass(), "CMSFilter Id " + ident == null? "Not Found" : ident.toString());
request.setAttribute(Constants.CMS_FILTER_IDENTITY, ident);

// If language is in session, set as query string
forward.append('?').append(WebKeys.HTMLPAGE_LANGUAGE + "=").append(String.valueOf(languageId));

Logger.debug(this.getClass(), "CMSFilter forward = " + forward.toString());
request.getRequestDispatcher(forward.toString()).forward(request, response);

} catch (Exception e) {
Expand All @@ -151,7 +164,7 @@ private void doFilterInternal(ServletRequest req, ServletResponse res, FilterCha
}

if (iAm._1() == IAm.PAGE) {

Logger.debug(this.getClass(), "CMSFilter iAm Page");
final StringWriter forward = new StringWriter().append("/servlets/VelocityServlet");

if (UtilMethods.isSet(queryString)) {
Expand All @@ -162,17 +175,21 @@ private void doFilterInternal(ServletRequest req, ServletResponse res, FilterCha
forward.append('?');
forward.append(queryString);
}
Logger.debug(this.getClass(), "CMSFilter forward = " + forward.toString());
request.getRequestDispatcher(forward.toString()).forward(request, response);
return;
}

// nothing to do here
if (uri.startsWith("/contentAsset/") && response.isCommitted()) {
Logger.debug(this.getClass(), "CMSFilter uri statrs with /contentAsset/ and response is committed");
return;
}

// allow vanities to forward to a dA asset
if(request instanceof VanityUrlRequestWrapper && !response.isCommitted() && (uri.startsWith("/dA/") || uri.startsWith("/contentAsset/")) ) {
Logger.debug(this.getClass(), "CMSFilter uri statrs with /dA/ or /contentAsset/ and response is not committed");
Logger.debug(this.getClass(), "CMSFilter URI = " + uri);
request.getRequestDispatcher(uri).forward(request, response);
return;
}
Expand Down
Loading

0 comments on commit 477606b

Please sign in to comment.