Debugging package

The Core module comes equipped with several classes that can be used to troubleshoot and/or debug your Magnolia instance. This page covers each of these classes and how they should be used. Always use caution when placing a filter in the chain manually and keep in mind that position in the chain matters. Depending on what you are trying to debug you may need to use a filter multiple times or even move it to different positions within the chain.

Servlet filters intercept and process requests or responses. They can do this either before the requests are sent to servlets or before the servlets send the responses back to clients. The Servlets filter chain defines the order in which filters are applied.

Always use caution when placing a filter in the chain manually and keep in mind that position in the chain matters. Depending on what you are trying to debug you may need to use a filter many times or even move it to different positions within the chain.

Never place a filter before the ContextFilter. Doing so will break your filter chain, generating a system failure in the Magnolia instance.
In recent Java versions, you can enable the Java Flight Recorder (JFR), a light recording feature (consuming about 1% of CPU processing) to record all your system’s events into a file, which you can download and analyze later.

Enabling filters

The general procedure for enabling filters is as follows.

  1. Download the filter.

  2. To enable a filter follow the steps below.

    1. Open the Configuration app and click the node: /server/filters.

    2. From the Action bar, click Import.

      The filter appears at the bottom of the chain.

    3. Drag (or move) the filter into position.

    4. Enable the filter by changing the enabled property to true.

Disabling filters

To disable a filter:

  1. Open the Configuration app and click the node: /server/filters.

  2. Select the filter you want to disable

  3. Change the enabled property to false.

  4. (Optional) Move the filter back down to the bottom of the chain.

Filters

Call tracking

class: info.magnolia.debug.CallTrackingFilter

This filter logs whatever has been recorded with the TrackingStatus.

Usage

Sometimes when debugging code you might need to track the number of calls made to method executed very deep down in the hierarchy on a per-request basis. Analyzing this with profiler can be very cumbersome. While it’s easy to see the total time required for complete operations, in some cases, you might need to see what each request thread was executing and how long that took. To get that data this filter analyzes the stacktrace and provides aggregated info about the call hierarchy.

Like the other filters in this package you need to enable the CallTrackingFilter in the filter chain as mentioned above. You will also need to call the track() method at the place where you want to see aggregated info from all the invocations.

Finally, here is an example output that shows the aggregated stacktrace from all invocations including counts of each execution path. With this information in hand, you can find (and hopefully fix) excessive calls.

2013-01-30 15:04:45,416 INFO info.magnolia.debug:
/magnoliaAuthor/demo-project.html:inits: 54, total calls: 14714, total time: 191947000
   14714;info.magnolia.debug.TrackingStatus.track(TrackingStatus.java:82)
     14714;info.magnolia.cms.util.SimpleUrlPattern.match(SimpleUrlPattern.java:212)
       4;info.magnolia.voting.voters.URIPatternVoter.boolVote(URIPatternVoter.java:60)

4;info.magnolia.cms.beans.config.DefaultVirtualURIMapping.mapURI(DefaultVirtualURIMapping.java:56)
    14706;info.magnolia.cms.security.PermissionImpl.match(PermissionImpl.java:89)
      4;info.magnolia.voting.voters.AbstractBoolVoter.vote(AbstractBoolVoter.java:62)
      4;info.magnolia.cms.beans.config.VirtualURIManager.getURIMapping(VirtualURIManager.java:107)
      14706;info.magnolia.cms.security.AccessManagerImpl.getPermissions(AccessManagerImpl.java:87)
        4;info.magnolia.cms.filters.VirtualUriFilter.getURIMapping(VirtualUriFilter.java:100)
        14706;info.magnolia.cms.security.AccessManagerImpl.isGranted(AccessManagerImpl.java:64)
        4;info.magnolia.voting.DefaultVoting.vote(DefaultVoting.java:56)
          14706;info.magnolia.cms.core.Access.isGranted(Access.java:63)
          4;info.magnolia.cms.filters.AbstractMgnlFilter.bypasses(AbstractMgnlFilter.java:121)
          4;info.magnolia.cms.filters.VirtualUriFilter.doFilter(VirtualUriFilter.java:66)

3742;info.magnolia.cms.core.DefaultHierarchyManager.isGranted(DefaultHierarchyManager.java:422)
    4;info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:88)
    47;info.magnolia.cms.core.DefaultHierarchyManager.isExist(DefaultHierarchyManager.java:396)
    4;info.magnolia.cms.filters.AbstractMgnlFilter.matches(AbstractMgnlFilter.java:94)
    10915;info.magnolia.cms.core.DefaultContent.newNodeDataInstance(DefaultContent.java:229)
    2;info.magnolia.cms.security.URISecurityFilter.isAuthorized(URISecurityFilter.java:98)
      2;info.magnolia.cms.security.URISecurityFilter.isAllowed(URISecurityFilter.java:82)
      4;info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81)
      246;info.magnolia.cms.core.DefaultContent.(DefaultContent.java:126)
      4;info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:82)

Removal

Once you are finished with the filter it’s a good idea to remove it or at least turn it off so that it stops logging. Remember, since every request will produce an output, the log can grow quickly.

Since every request produces an output, the log can grow quickly.

The best thing to do is to disable the filter. This way if you need it again in the future, you can turn it back on.

Derby test persistence manager

class: info.magnolia.debug.DerbyTestPersistenceManager

The persistence manager implementation measures the time spent saving data. You must also enable the PerformanceTestFilter.

While this specific implementation is meant to be used with Derby database it should be quite straightforward to create an implementation for any other database.

Deployment

To deploy this class:

  1. Create a new repository configuration which uses the test persistence manager. Here is an example:

    jackrabbit-bundle-derby-test-search.xml
    <PersistenceManager class="info.magnolia.debug.DerbyTestPersistenceManager">
  <param name="url" value="jdbc:derby:${wsp.home}/db;create=true" />
  <param name="schemaObjectPrefix" value="${wsp.name}_" />
</PersistenceManager>

  2. In your properties file update the JR config to point to the test configuration.

    magnolia.repositories.home=${magnolia.home}/repositories-test
magnolia.repositories.jackrabbit.config=WEB-INF/config/repo-conf/jackrabbit-bundle-derby-test-search.xml

  3. Start up the instance and let it create a new test repository.

  4. Configure the PerformanceTestFilter behind the context filter (see instructions below).

    We need the PerformanceTestFilter because this is the filter that will print the time data to the standard log. The time data is stored in a PerformanceTestStatus object.

Usage

The point of this class is to examine how long it takes to persist (store) data.

Typically it’s not a good idea to use an embedded database in a production environment. The embedded database will have to share memory with the application.

Let’s look at an example where we upload a large file (100M+) into the DAM so we can measure the time it takes to persist it. Create a new asset in the DAM and upload the new file in the detail subapp. Once you click save, you should see some information printed to the standard log via the PerformanceTestFilter. Times are in milliseconds.

2019-06-14 11:16:45,381 INFO info.magnolia.debug : /magnoliaAuthor/.magnolia/admincentral/UIDL/ : performanceTestFilter: 2092, pm-store: 680, pm-blob: 670

Removal

Once the test is complete revert back to your repository.

  1. In your properties file, update the JR config to point to the original configuration.

    magnolia.repositories.home=${magnolia.home}/repositories
magnolia.repositories.jackrabbit.config=WEB-INF/config/repo-conf/jackrabbit-bundle-derby-search.xml

Dump headers

class: info.magnolia.debug.DumpHeadersFilter

This filter dumps the headers for the request and the response.

Usage

The point of the DumpHeadersFilter is to print header information for each request and response to the standard log. This can be helpful for examining requests and their origin. Especially when the request passes through other servers before arriving in Magnolia. On the response side of things, double check that a specific header is being set before leaving Magnolia.

Let’s look at a specific example of deploying to filter at the top of the chain. This is probably the most common use case of the filter. We place the filter near the top of the chain right behind the context filter. Never place the filter above context because this will break the system.

Once the filter is deployed you can begin examining the requests. The request does not need to be for a website. Remember that all requests, even those for Admincentral, go through the filter chain. This means any request could be examined and (with this filter deployed) all requests will produce output in the log.

Here we see an example of requesting the travel home page:

Each request will have a number associated with it. This way we can match the request to the response. In the example below, that number is 8.

 
# Request
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 uri: /magnoliaPublic/travel.html
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 session: true
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 parameters:
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 method: GET
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 header: host=localhost:8080
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 header: connection=keep-alive
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 header: cache-control=max-age=0
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 header: upgrade-insecure-requests=1
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 header: user-agent=Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36 OPR/60.0.3255.160
2019-06-12 16:32:03,969 INFO info.magnolia.debug : 8 header: accept=text/html,application/xhtml-xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
2019-06-12 16:32:03,970 INFO info.magnolia.debug : 8 header: accept-encoding=gzip, deflate, br
2019-06-12 16:32:03,970 INFO info.magnolia.debug : 8 header: accept-language=en-US,en;q=0.9
2019-06-12 16:32:03,970 INFO info.magnolia.debug : 8 header: cookie=JSESSIONID=214520A11DA4335D81735380B0BA06F8; _first_pageview=1; _jsuid=4186500974; no_tracky_100843699=1

# Response
2019-06-12 16:32:04,130 INFO info.magnolia.debug : 8 response status: 200
2019-06-12 16:32:04,130 INFO info.magnolia.debug : 8 response length: 5483
2019-06-12 16:32:04,130 INFO info.magnolia.debug : 8 response mime type: text/html;charset=UTF-8
2019-06-12 16:32:04,130 INFO info.magnolia.debug : /magnoliaPublic/travel.html response: X-Magnolia-Registration = Registered

Removal

Once you are finished with the filter it’s a good idea to remove it or at least turn it off so that it stops logging. Remember, since every request will produce an output, the log can grow quickly.

Probably the best thing to do is disable the filter. This way if you need it again in the future, you can turn it back on.

Logging response

class: info.magnolia.debug.LoggingResponse

This class wraps a response and records the set headers and http status for debugging purposes.

Performance test

class: info.magnolia.debug.PerformanceTestFilter

The point of this filter is to log the round-trip time it takes to fulfill the requests. The filter logs the data recorded by the PerformanceTestStatus class to the standard output, providing more details about the system’s performance in milliseconds.

Usage

To use the filter, you need to decide where to place it in the filter chain. In the standard output below, the filter was the second filter in the chain (after the context filter). Everything below the filter is included in the time measurement, and so, in this case, it is about the total time to fulfill the request.

INFO info.magnolia.debug : /magnoliaPublic/travel.html : performanceTestFilter: 154

Sometimes, you should move this filter down the chain. For example, putting it just before the cms subchain tells you how long it takes to render a specific request. Again, the time is printed to the standard output in milliseconds.

Removal

Once you are finished with the filter it’s a good idea to remove it or at least turn it off so that it stops logging. Remember since every request will produce an output the log can grow quickly.

The best thing to do is to disable the filter. This way if you need it again in the future, you can turn it back on.

Session debugger

class: info.magnolia.debug.SessionDebugger

This is a filter and listener that can help to debug session issues.

Usage

The point of this filter is to log session information. Configure it behind the context filter to see all session data in the log.

2019-06-14 14:10:00,272 WARN info.magnolia.debug : -- Session found
-- Session attributes :
    com.vaadin.server.VaadinSession.AdminCentral = com.vaadin.server.VaadinSession@1ea60cc1
    Key[type=info.magnolia.personalization.trait.storage.StorageAwareTraitCollector$SessionScopedTraitStorage, annotation=[none]] = info.magnolia.personalization.trait.storage.StorageAwareTraitCollector$SessionScopedTraitStorage@1d4950db
    AdminCentral.lock = java.util.concurrent.locks.ReentrantLock@2f872e69[Unlocked]
    javax.security.auth.Subject = Subject:
    Principal: MgnlUser - superuser [51ae3379-67cf-4994-9e05-f97cb8bc3e4a]
    Principal: info.magnolia.cms.security.Realm$RealmImpl@179a1
    Principal: RoleListImpl[name=roles,list=[workflow-base, rest-admin, publisher, superuser]]
    Principal: GroupListImpl[name=groups,list=[publishers]]
    Principal: PrincipalCollectionImpl[name=PrincipalCollection]

-- Session is new : false
----------

Removal

Once you are finished with the filter it’s a good idea to remove it or turn it off so that it stops logging. Remember, since every request will produce an output, the log can grow quickly.

The best thing to do is to disable the filter. This way if you need it again in the future, you can turn it back on.
Feedback

DX Core

×

Location

This widget lets you know where you are on the docs site.

You are currently perusing through the DX Core docs.

Main doc sections

DX Core Headless PaaS Legacy Cloud Incubator modules