Question about mina - deadlock?

[Brian Parkinson <pa...@ecobee.com>]

Hello:

I have a question about mina - wondering if someone out there has a couple minutes to help out:

I have a server running mina-2.0.0M1 (which is pretty old) which opens both a non-SSL and SSL ports. There are two issues I'm seeing in production - I'm not sure that this is mina related - still investigating, but right now, it looks to be comms related.

1. Every 4 days or so (so far, can't correlate to anything) the server "locks up" and refuses all subsequent requests (?). Trying to narrow down, I have been informed that there may be an issue with mina-core-2.0.0M1, and I should upgrade to mina-core-2.0.0M6. I've done this - the compile was pretty straightforward. The init code is attached below - does this look correct - just want to make sure that I'm not doing something wrong which might cause resources to leak over time.

2. I've noticed one recurring error in my log files - in my HttpRequestDecoder (extends MessageDecoderAdapter), I am throwing an exception trying to parse up the headers - the code ends up getting "partial line" headers (for example, the decoder attempts to parse a line "Content-Ty" with nothing else on the line) - it seems like the HTTP packet is not complete - should I be concerned about this? An exception is thrown, and the caller will re-send anyways, but the error is seen a fair bit throughout the logs, and I'm wondering if this might be contributing to the lock up issue (?).

Any help is appreciated - I'm flying a bit blind trying to track this down.

Regards,

Brian Parkinson
ecobee inc.
parki@ecobee.com

---

Here's how the mina server is set up:

private void start()
{
	makeConnection(8382, false);
	makeConnection(8383, true);
}

private void makeConnection(int port, boolean sslEnabled) throws Exception
{
	// Create an acceptor
	NioSocketAcceptor acceptor = new NioSocketAcceptor();
	
    DefaultIoFilterChainBuilder chain = acceptor.getFilterChain();

	// Create a service configuration
    chain.addLast("protocolFilter", new ProtocolCodecFilter(new HttpServerProtocolCodecFactory()));
		
	if(sslEnabled)
	{
		Log.info(Server.class, "start", "Adding SSL filter."); 
		
		SslFilter sslFilter = new SslFilter(SslContextFactory.getServerContext());
		
		chain.addFirst("sslFilter", sslFilter);
	}
	
	if(logEnabled_)
	{
		Log.info(Server.class, "start", "Adding log filter."); 
		
		chain.addLast("logger", new LoggingFilter());
	}
	        
    // Add in the custom filter which manages session information within the server.
	// Add to the front of the chain, as we trap everything we need to here.
    chain.addFirst("myFilter", new ServerFilter(sslEnabled));

    // Set up the local address.
	acceptor.setDefaultLocalAddress(new InetSocketAddress(port));
	
	// Create the server handler and bind id to the acceptor.
	RequestHandler handler = new RequestHandler(sslEnabled);
	acceptor.setHandler(handler);
	acceptor.bind();
}

RE: Question about mina - deadlock?

[Brian Parkinson <pa...@ecobee.com>]

Emmanuel writes:

"Can you post your decodable() and doDecode() methods ?"

Below is the code for the request decoder.

Any help is super-appreciated - 

Regards,

Brian...

--- x8 snip


package com.ecobee.communicator.server.mina;

import java.io.BufferedReader;
import java.io.IOException;
import java.io.StringReader;
import java.nio.charset.Charset;
import java.nio.charset.CharsetDecoder;
import java.util.*;

import com.ecobee.communicator.server.IServer;

import com.ecobee.foundation.Container;
import com.ecobee.foundation.net.*;
import com.whatevernot.util.Log;
import org.apache.mina.common.IoBuffer;
import org.apache.mina.common.IoSession;
import org.apache.mina.filter.codec.ProtocolDecoderOutput;
import org.apache.mina.filter.codec.demux.MessageDecoderAdapter;
import org.apache.mina.filter.codec.demux.MessageDecoderResult;

/**
 * A request decoder, which handles the parsing of the incoming requests. This
 * is heavily adapted from the mina example code, but contains a number of changes
 * since we don't restrict communications to request and response.
 * @author The Apache MINA Project (dev@mina.apache.org)
 * @version $Rev: 593479 $, $Date: 2007-11-09 05:21:35 -0500 (Fri, 09 Nov 2007) $
 */
public class HttpRequestDecoder extends MessageDecoderAdapter
{
	final private static String DEFAULT_CONTENT_TYPE =
		((IServer) Container.getContext().getBean("server")).getDefaultContentType();
	
	final private static byte[] CONTENT_LENGTH = new String("Content-Length:").getBytes();
	final private static int CONTENT_LENGTH_LENGTH = CONTENT_LENGTH.length;
	
	final private CharsetDecoder DECODER = Charset.defaultCharset().newDecoder();

	private class ParseContext
	{
		private int offset;
		private IoBuffer in;
		public ParseContext(int offset, IoBuffer in)
		{
			this.offset = offset;
			this.in = in;
		}
	}
	
	/**
	 * Default constructor, as this object is created dynamically.
	 */
	public HttpRequestDecoder()
	{
	}
	
	/**
	 * @see MessageDecoderAdapter#decodable
	 */
	public MessageDecoderResult decodable(IoSession session, IoBuffer in)
	{	
		try
		{	
			boolean value = messageComplete(in);
			
			if(value)
			{				
				return MessageDecoderResult.OK;
			}
			else
			{
				// Return NEED_DATA if the whole header is not read yet.
				return MessageDecoderResult.NEED_DATA;
			}
	    }
		catch (Exception ex)
		{
			Log.error(this, "decodable", "Exception decoding HTTP request.", ex);
			
			return MessageDecoderResult.NOT_OK;
	    }    
	}
	
	/**
	 * @see MessageDecoderAdapter#decode
	 */
	public MessageDecoderResult decode(IoSession session, IoBuffer in, ProtocolDecoderOutput out)
		throws Exception
	{
		ParseContext parseContext = new ParseContext(0, in);
		
		// Loop, as it's possible that there is more than one message in the buffer.
		while(true)
		{
			IHttpRequest request = parseRequest(parseContext);
			
			if(request == null) break;

			out.write(request);
		}
			
		return MessageDecoderResult.OK;
	}
	
	private boolean messageComplete(IoBuffer in) throws Exception
	{
		// We need at least 4 bytes to make any sense of the request.
		if(in.remaining() < 4)
		{
			return false;
		}
		
		// Loop forwards looking for the line separator 0x0D 0x0A 0x0D 0x0A.
		int lineSeparatorIndex = findSeparator(in);
		
		if(isGet(in))
		{
			// If there is a line separator, we have a valid GET request.
			return (lineSeparatorIndex != -1);
		}
		
		if(isPost(in))
		{
			// If there is no valid separator, then the POST request is invalid.
			if(lineSeparatorIndex == -1)
			{
				return false;
			}

			int last = in.remaining() - 1;
			for (int i = 0; i <= (last - CONTENT_LENGTH_LENGTH); i++)
            {
				boolean found = false;
				
				for(int j = 0; j < CONTENT_LENGTH_LENGTH; j++)
				{					
				    if(in.get(i + j) != CONTENT_LENGTH[j])
				    {
				    	found = false;
				    	break;
				    }
				    found = true;
				}

				if(found)
				{
					// Retrieve value from this position till next 0x0D 0x0A.
					StringBuilder contentLength = new StringBuilder();
					for(int j = i + CONTENT_LENGTH.length; j < last; j++)
					{
						if (in.get(j) == 0x0D) break;
						
						contentLength.append(new String(new byte[] { in.get(j) }));
					}
					
					int intContentLength = Integer.parseInt(contentLength.toString().trim());
		
					// If content-length worth of data has been received then the message is complete.
					return ((lineSeparatorIndex + 4 + intContentLength) <= in.remaining());
				}
			}
		}

		// The message is not complete and we need more data.
	    return false;
	}
	
	private IHttpRequest parseRequest(ParseContext parseContext) throws IOException
	{
		int offset = parseContext.offset;
		IoBuffer in = parseContext.in;
		
		// Find the line separator.
		int separatorIndex = findSeparator(in, offset);
		
		// If there is no separator, we need more data.
		if(separatorIndex == -1) return null;
		
		// The end of the message is the separator index + size of the separator.
		int endOfMessage = separatorIndex + 4;

		// Update the parse context offset to the beginning of the next message, if any.
		parseContext.offset = endOfMessage;
		
		String contents = in.getString(endOfMessage - offset, DECODER);

		BufferedReader reader = new BufferedReader(new StringReader(contents));

		String firstLine = reader.readLine();
		if(firstLine == null) return null;
		
		String[] url = firstLine.split(" ");

		if (url.length < 3) return null;
	
		String method = url[0].toUpperCase();
		String context = url[1];
		String protocol = url[2];
		
		Map<String, String> headers = new HashMap<String, String>();
		
		// Parse up the headers.
		while(true)
		{
			String line = reader.readLine();
			
			if((line == null) || (line.length() == 0)) break;
			
			String[] tokens = line.split(": ");
			if(tokens.length == 2)
			{
				headers.put(tokens[0], tokens[1]);
			}
			else if(tokens.length == 1)
			{
				headers.put(tokens[0], "");
			}
			else
			{
				Log.error(this, "parseRequest", "Cannot parse partial header: " + line + " firstLine: " + firstLine);
				return null;
			}
		}
		
		// Determine if the request is compressed and/or encrypted or not.
		String contentType = headers.get(IHttpRequest.CONTENT_TYPE_HEADER);
		if(contentType == null) contentType = DEFAULT_CONTENT_TYPE;

		IHttpRequest request = makeRequest(contentType);
		
		request.setMethod(method);
		request.setContext(context);
		request.setProtocol(protocol);
		
		Iterator<String> iterator = headers.keySet().iterator();
		while(iterator.hasNext())
		{
			String key = iterator.next();
			String value = headers.get(key);
			request.setHeader(key, value);
		}
		
		// Parse up any parameters.
		int idx = context.indexOf('?');
		if(idx != -1)
		{
			// The context becomes everything up to the '?' character.
			request.setContext(context.substring(0, idx));
			
			// The parameter list is everything else.
	        String params = url[1].substring(idx + 1);
	        
	        // Split up the parameter list.
			String[] match = params.split("\\&");
			for(String element : match)
			{
				String[] tokens = element.split("=");

				switch(tokens.length)
				{
				case 0:
					request.setParameter(element, "");
				    break;
				case 1:
					request.setParameter(tokens[0], "");
					break;
				default:
					request.setParameter(tokens[0], tokens[1]);
					break;
				}
			}
		}

		// If method 'POST' then read Content-Length worth of data
		if(request.getMethod() == IHttpRequest.HttpMethod.POST)
		{
			int contentLength = request.getContentLength();

			byte[] bodyBytes = new byte[contentLength];
			
			in.get(bodyBytes, 0, contentLength);

			request.setBodyBytes(bodyBytes);
		}

		return request;
	}
	
	private int findSeparator(IoBuffer in)
	{
		return findSeparator(in, 0);
	}
	
	private int findSeparator(IoBuffer in, int offset)
	{
		int last = in.remaining() - 1;
		for(int i = offset; i <= last - 3; ++i)
		{
			if(isSeparator(in, i)) return i;
		}	
		return -1;
	}
	
	private boolean isSeparator(IoBuffer in, int i)
	{
		return ((in.get(i) == (byte) 0x0D &&
			in.get(i + 1) == (byte) 0x0A && 
			in.get(i + 2) == (byte) 0x0D &&
			in.get(i + 3) == (byte) 0x0A));
	}
	
	private boolean isGet(IoBuffer in)
	{
		return (in.get(0) == (byte) 'G') &&
		(in.get(1) == (byte) 'E') &&
		(in.get(2) == (byte) 'T');
	}
	
	private boolean isPost(IoBuffer in)
	{
		return ((in.get(0) == (byte) 'P') &&
			(in.get(1) == (byte) 'O') &&
			(in.get(2) == (byte) 'S') &&
			(in.get(3) == (byte) 'T'));
	}

	private IHttpRequest makeRequest(String contentType)
	{
		if(IHttpRequest.AES_CONTENT_TYPE.equals(contentType))
		{
			return new AesInboundHttpRequest();
		}
		else if(IHttpRequest.ZLIB_CONTENT_TYPE.equals(contentType))
		{
			return new ZLibInboundHttpRequest();
		}
		else
		{
			return new HttpRequest();
		}	
	}
}

Re: Question about mina - deadlock?

[Emmanuel Lecharny <el...@apache.org>]

Brian Parkinson wrote:
> Emmanuel writes: 
>
> ---x8 snip
>
>   
>> 2. I've noticed one recurring error in my log files - in my HttpRequestDecoder (extends MessageDecoderAdapter), I am throwing an exception trying to parse up the headers - the code ends up getting "partial line" headers (for example, the decoder attempts to parse a line "Content-Ty" with nothing else on the line) - it seems like the HTTP packet is not complete - should I be concerned about this? An exception is thrown, and the caller will re-send anyways, but the error is seen a fair bit throughout the logs, and I'm wondering if this might be contributing to the lock up issue (?).
>>     
>    
> You have no guarantee that the messages sent by a client will be received fully. They can even been sent one byte at a time. It's up to you to gather all the incoming bytes until you have enough bytes to decode your protocol. In your case, however, you can use the TextLineDecoder which waits for a line feed to forward the decoded message to your handler.
>
> ---x8 snip
>
> I am using a custom HttpRequestDecoder (which subclasses MessageDecoderAdaptor). The 'decodable' method looks correct, but then when 'decode' gets called, the buffer is incomplete - I can't figure that out. Almost invariably, the 'decode' method fails on an incomplete header line - I see a truncated header 'Content-Ty' repeatedly in the logs. 
>   
Can you post your decodable() and doDecode() methods ?

-- 
--
cordialement, regards,
Emmanuel Lécharny
www.iktek.com
directory.apache.org

RE: Question about mina - deadlock?

[Brian Parkinson <pa...@ecobee.com>]

Emmanuel writes: 

---x8 snip

> 2. I've noticed one recurring error in my log files - in my HttpRequestDecoder (extends MessageDecoderAdapter), I am throwing an exception trying to parse up the headers - the code ends up getting "partial line" headers (for example, the decoder attempts to parse a line "Content-Ty" with nothing else on the line) - it seems like the HTTP packet is not complete - should I be concerned about this? An exception is thrown, and the caller will re-send anyways, but the error is seen a fair bit throughout the logs, and I'm wondering if this might be contributing to the lock up issue (?).
   
You have no guarantee that the messages sent by a client will be received fully. They can even been sent one byte at a time. It's up to you to gather all the incoming bytes until you have enough bytes to decode your protocol. In your case, however, you can use the TextLineDecoder which waits for a line feed to forward the decoded message to your handler.

---x8 snip

I am using a custom HttpRequestDecoder (which subclasses MessageDecoderAdaptor). The 'decodable' method looks correct, but then when 'decode' gets called, the buffer is incomplete - I can't figure that out. Almost invariably, the 'decode' method fails on an incomplete header line - I see a truncated header 'Content-Ty' repeatedly in the logs. 

A lot of this code was written > 1 year ago and based on M1. Should I be decoding differently?

Thanks.

Brian Parkinson
ecobee.com

Re: Question about mina - deadlock?

[Emmanuel Lecharny <el...@apache.org>]

Brian Parkinson wrote:
> Hello:
>
> I have a question about mina - wondering if someone out there has a couple minutes to help out:
>
> I have a server running mina-2.0.0M1 (which is pretty old) which opens both a non-SSL and SSL ports. There are two issues I'm seeing in production - I'm not sure that this is mina related - still investigating, but right now, it looks to be comms related.
>
> 1. Every 4 days or so (so far, can't correlate to anything) the server "locks up" and refuses all subsequent requests (?). Trying to narrow down, I have been informed that there may be an issue with mina-core-2.0.0M1, and I should upgrade to mina-core-2.0.0M6. I've done this - the compile was pretty straightforward. The init code is attached below - does this look correct - just want to make sure that I'm not doing something wrong which might cause resources to leak over time.
>   
Seems ok to me.
> 2. I've noticed one recurring error in my log files - in my HttpRequestDecoder (extends MessageDecoderAdapter), I am throwing an exception trying to parse up the headers - the code ends up getting "partial line" headers (for example, the decoder attempts to parse a line "Content-Ty" with nothing else on the line) - it seems like the HTTP packet is not complete - should I be concerned about this? An exception is thrown, and the caller will re-send anyways, but the error is seen a fair bit throughout the logs, and I'm wondering if this might be contributing to the lock up issue (?).
>   
You have no guarantee that the messages sent by a client will be 
received fully. They can even been sent one byte at a time. It's up to 
you to gather all the incoming bytes until you have enough bytes to 
decode your protocol. In your case, however, you can use the 
TextLineDecoder which waits for a line feed to forward the decoded 
message to your handler.

I think it's described on the sparse doco...

-- 
--
cordialement, regards,
Emmanuel Lécharny
www.iktek.com
directory.apache.org