[FELIX-5032] IndexOutOfBoundsException in SCR ComponentTestBase class

• Type: Bug
• Status: Closed
• Priority: Minor
• Resolution: Fixed
• Affects Version/s: scr-2.0.0
• Fix Version/s: scr-2.0.4
• Component/s: Declarative Services (SCR)
• Assignee: David Jencks
• Reporter: Pierre De Rop
• Created: 12/Sep/15 15:24
• Updated: 08/Jul/16 08:05
• Resolved: 20/Oct/15 02:14

Description

In the SCR integration tests, there is an issue in the ComponentTestBase.Log.run() method:

When a warn message is logged, and if the current test includes a part of the warn message in the "ignoredWarnings" attributes, then the Log.run() method may get an ArrayIndexOutOfBound exception, and the message is not logged.

Moreover, this exception kills the thread that is internally used by the ComponentTestBase.Log, so any further log won't be displayed at all.

Here is where the bug is located (see ComponentTestBase.Log inner class, line 919):

 ...
        public void run()
        {
            try
            {
                LogEntry entry = null;
                while ( true )
                {
                    entry = m_logQueue.take();
                    if ( entry.getLevel() <= 2 )
                    {
                        if ( m_warnings.size() < 1024 && acceptWarning( entry.getMessage() ) )
                        {
                            m_warnings.add( entry.getMessage() );
                        }
                        else
                        {
                            // Avoid out of memory ...
                            m_warnings.set( 1023, "Unexpected errors logged. Please look at previous logs" );
                        }
                    }
   ...

Here, if the test generates a warn log that can be ignored (the acceptWarning method will return false), then the m_warnings list is immediately set to 1023, and if the current size of the list is lower than 1024 (which is the case at the begining), then the logging thread will get an ArrayIndexOutOfMemory exception.

(This exception was never noticed because the stdout/stderr logs are disabled.)

I have attached a simple patch that corrects the problem.
The patch also does two new thing:

• By default, the DS_LOGLEVEL is set to "warn" in order to reduce output when we want to simply run all the tests before doing a release and check if eveything is ok.

• when a warn message is not accepted (is actually expected by the test), then it is not logged when DS_LOGLEVEL is set to "warn". However, of course the expected warn message is logged when running with DS_LOGLEVEL="debug".

Here is the patch (also attached to this issue)

                    if ( entry.getLevel() <= 2 )
                    {
                    	// If the test does not accept this warning, it means this warning is expected by the test.
                    	if (acceptWarning( entry.getMessage())) {
                    		if ( m_warnings.size() < 1024 )
                    		{
                        		// Store this warning so any test can check if some warnings have been generated.
                    			m_warnings.add( entry.getMessage() );
                    		}
                    		else
                    		{
                    			// Avoid out of memory ...
                    			m_warnings.set( 1023, "Unexpected errors logged. Please look at previous logs" );
                    		}
                    	} else {
                    		// The current test explicitly said that this warning is not accepted and is expected.
                    		// So, unless we are in full debug, don't display this expected warning message.
                    		if (! DS_LOGLEVEL.equals("debug")) {
                    			continue;
                    		}
                    	}
                    }