Sling POST servlet HTTP 500 error. POST parameters are being scrambled.

[EV909]

Hello,

We've been trying to troubleshoot an issue with the default sling post servlet and i'm hoping someone has experienced this before. We have javascript on our page that POSTs several nodes/properties when the user clicks a button. For a handful of users (randomly/not very often) when they click the button the server will return a 500 error and based on the logs it appears that the parameters passed in the POST request are being chopped up/spliced. However, when viewing the original request from the browser the parameters look fine. Here is an example of the call (typically ~2020 property/value pairs)

{
  "request": {
  "method": "POST",
  "url": "<SERVERNAME>/content/km/categories/national-billing-issues/209594",
  "httpVersion": "HTTP/1.1",
  ....
  "headersSize": 4802,
  "bodySize": 240671,
  "postData": {
    "mimeType": "application/x-www-form-urlencoded; charset=UTF-8",
    "text": "jcr%3Acontent%2Fpagecontent%2Fopttabs%2Fcustomer-communication%2Fblockcontent%2FchannelSettings=undefined%3Dselectallchannel%24false&jcr%3Acontent%2Fpagecontent%2Fopttabs%2Fcustomer-commu<ALL PARAMS LISTED IN ONE LINE...>",
    "params": [
      {
        "name": "jcr%3Acontent%2Fpagecontent%2Fopttabs%2Fcustomer-communication%2Fblockcontent%2FchannelSettings",
        "value": "undefined%3Dselectallchannel%24false"
      },
      {
        "name": "jcr%3Acontent%2Fpagecontent%2Fopttabs%2Fcustomer-communication%2Fblockcontent%2FchannelSettings",
        "value": "Business+%26+Government%3Dbusiness-government%24false"
      },
      {
        "name": "jcr%3Acontent%2Fpagecontent%2Fopttabs%2Fcustomer-communication%2Fblockcontent%2FchannelSettings",
        "value": "+B2B+(Gov't+Sales)%3Db2b-governmentsales%24false"
      },
      .....<SIMILAR PARAMETERS ~2000 TIMES>....
    ]
  }
},
"response": {
  "status": 500,
  "statusText": "Server Error",
  "httpVersion": "HTTP/1.1",
  ......

And from the server logs we see things like this -

Trying to save an incorrect path that was not in our request (/t/contents instead of /jcr:content/pagecontent):

Trying to save a property with prefix "cjcr":

Parameters spliced to form bad escape sequence:

Trying to save part of a property value as a property name:

The main goal of this post request is to save multi value parameters (channelSettings) to each component on the page with values like (TagTitle%3Dtag-name%24false). It usually works fine except for these one-off issues.

If anyone has any ideas i would appreciate it or even suggestions on how to debug. I haven't been able to find a way to log POST request parameters as they get to the server to see if something is breaking them up before they get to AEM. Currently using 6.3 with SP1

Thanks

[smacdonald2008]

Are you posting to a custom Servlet?

[EV909]

No, this is just posting directly to the page node using the default sling servlet

[smacdonald2008]

I was hoping it was a custom servlet - that way you could log the parameters. As you are using the default POST servlet - you cannot really log messages. Let see if other community members have seen this. If you fo not hear anything - open a ticket. This should not  be occurring.

[VeenaVikraman]

Will it be possible to provide a sample code for us to troubleshoot ?

[atyaf66]

It's really hard to diagnose what's happening here without logs. You can use Apache Sling :: Log Tracer  to trace the request logs for your specific path and it provides fine control over request logging. It might help give you an idea of what is happening. You can also use Apache Sling :: Request Processing Analyzer (reqanalyzer)  to analyze the requests and see if there are any filters that modify the request before it reaches the default sling servlet. hope this helps!

[EV909]

Thanks, i'll take a look at that logging config and see if that helps at all. I did try to enable debug logging for - org.apache.sling.servlets.post.impl - to see if i could get anything out of that, but it wasn't too helpful.

Will have to think about sample code, it's really not much more than sending that POST request to the server as i have confirmed the POST request looks good when it leaves the browser.

At this point i think my only options left to pursue are opening a ticket and attempting to write a custom servlet that mimics the default POST servlet.

[atyaf66 · Accepted solution]

You dont have to re-write the default servlet, assuming it is working properly and the issue is related to something else. You can use request dispatcher to forward the request from your custom servlet to the default sling servlet, see this: Apache Sling :: Dispatching Requests you can even use this approach to debug the request before it's handled by the default servlet.

[EV909]

Oh, yes that's a great idea, thank you! That will at least let me debug whether the issue lies within the default servlet or on the network before it gets to AEM.

[EV909]

Here's what i ended up finding - I created the filter for logging as atyaf66 suggested and i could see that the POST request is being truncated before it gets to AEM. Here's an example of a working call and the bad call -

vs

So something is just removing the first part of the POST body. Will have to identify what in our network would allow that to happen. Thanks for the support!

Here is the filter i ended up throwing together -

@Component(immediate=true, enabled=true)
@Service(value=Filter.class)
@Properties({
    @Property(name="sling.filter.scope", value="REQUEST", propertyPrivate=true),
    @Property(name="service.ranking", intValue=1000001, propertyPrivate=true)
})
public class ParamPostFilter implements javax.servlet.Filter {
    Logger log = LoggerFactory.getLogger(this.getClass());
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain filterChain) throws IOException, ServletException {
        HttpServletRequest httpRequest = (HttpServletRequest)request;
        try {
            if (httpRequest.getMethod().equalsIgnoreCase("POST")) {
                log.debug("********* Caught POST **********");
                Enumeration<String> params = request.getParameterNames(); 
                StringBuilder sb = new StringBuilder();
                while(params.hasMoreElements()){
                    String paramName = params.nextElement();
                    String[] paramValues = request.getParameterValues(paramName);
                     for (int k = 0; k < paramValues.length; k++) {
                         sb.append(paramName + "=" + paramValues[k] + "&");
                     }
                }
                log.debug(sb.toString());
            }
        } catch (Exception e) {
            log.error("POST filter failure", e);
        }
        filterChain.doFilter(request, response);
    }
}