test/Logging/EPTF_Logging_test.ttcn

///////////////////////////////////////////////////////////////////////////////
//                                                                           //
// Copyright (c) 2000-2017 Ericsson Telecom AB                               //
//                                                                           //
// All rights reserved. This program and the accompanying materials          //
// are made available under the terms of the Eclipse Public License v2.0     //
// which accompanies this distribution, and is available at                  //
// https://www.eclipse.org/org/documents/epl-2.0/EPL-2.0.html                                 //
///////////////////////////////////////////////////////////////////////////////

///////////////////////////////////////////////////////////
//  Module: EPTF_Logging_test
// 
//  Purpose:
//    Test file for Logging feature.
// 
///////////////////////////////////////////////////////////

module EPTF_Logging_test {

//=========================================================================
// Import Part
//=========================================================================

import from EPTF_CLL_Logging_Definitions all;
import from EPTF_CLL_Logging_Functions all;
import from EPTF_CLL_Base_Functions all;

//=========================================================================
//Component Types
//=========================================================================

type component LogTest_CT extends EPTF_Logging_CT 
{
  var charstring v_temp := "";
}

function f_EPTF_Logging_Test_Generic1() runs on EPTF_Logging_CT {
  f_EPTF_Logging_init_CT("LogTest");
  
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{0},"0");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{1},"1");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{2},"2");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{3},"3");

  log ("Logging disabled on component for all features");
  f_EPTF_Logging_disableAllLocal();
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{0},"DIS_ALL:0");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{1},"DIS_ALL:1");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{2},"DIS_ALL:2");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{3},"DIS_ALL:3");
  log ("Logging enabled on component for all features");
  f_EPTF_Logging_enableAllLocal();
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{0},"ENA_ALL:0");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{1},"ENA_ALL:1");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{2},"ENA_ALL:2");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{3},"ENA_ALL:3");
  log ("Logging disabled on component");
  f_EPTF_Logging_disableLocal(v_EPTF_Logging_myMaskId);
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{0},"DIS:0");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{1},"DIS:1");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{2},"DIS:2");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{3},"DIS:3");
  log ("Logging enabled on component");
  f_EPTF_Logging_enableLocal(v_EPTF_Logging_myMaskId);
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{0},"ENA:0");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{1},"ENA:1");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{2},"ENA:2");
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{3},"ENA:3");
  log("Event class 2 is disabled");
  f_EPTF_Logging_disableLocalMask(v_EPTF_Logging_myMaskId, 2);
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{2},"DIS_CL:2");
  log("Event class 2 is enabled");
  f_EPTF_Logging_enableLocalMask(v_EPTF_Logging_myMaskId, 2);
  f_EPTF_Logging_log(true,v_EPTF_Logging_myMaskId,{2},"ENA_CL:2");
}

function f_EPTF_Logging_Test_Generic2() runs on EPTF_Logging_CT {
  f_EPTF_Logging_init_CT("LogTest");

  f_EPTF_Logging_error(true,"0");
  f_EPTF_Logging_warning(true,"1");
  f_EPTF_Logging_debug(true,"2");
  f_EPTF_Logging_debugM(true,"3");
  f_EPTF_Logging_debugV(true,"4");

  log ("Logging disabled on component for all features");
  f_EPTF_Logging_disableAllLocal();
  f_EPTF_Logging_error(true,"DIS_ALL:0");
  f_EPTF_Logging_warning(true,"DIS_ALL:1");
  f_EPTF_Logging_debug(true,"DIS_ALL:2");
  f_EPTF_Logging_debugM(true,"DIS_ALL:3");
  f_EPTF_Logging_debugV(true,"DIS_ALL:4");
  log ("Logging enabled on component for all features");
  f_EPTF_Logging_enableAllLocal();
  f_EPTF_Logging_error(true,"ENA_ALL:0");
  f_EPTF_Logging_warning(true,"ENA_ALL:1");
  f_EPTF_Logging_debug(true,"ENA_ALL:2");
  f_EPTF_Logging_debugM(true,"ENA_ALL:3");
  f_EPTF_Logging_debugV(true,"ENA_ALL:4");
  log ("Logging disabled on component");
  f_EPTF_Logging_disableLocal(v_EPTF_Logging_myMaskId);
  f_EPTF_Logging_error(true,"DIS:0");
  f_EPTF_Logging_warning(true,"DIS:1");
  f_EPTF_Logging_debug(true,"DIS:2");
  f_EPTF_Logging_debugM(true,"DIS:3");
  f_EPTF_Logging_debugV(true,"DIS:4");
  log ("Logging enabled on component");
  f_EPTF_Logging_enableLocal(v_EPTF_Logging_myMaskId);
  f_EPTF_Logging_error(true,"ENA:0");
  f_EPTF_Logging_warning(true,"ENA:1");
  f_EPTF_Logging_debug(true,"ENA:2");
  f_EPTF_Logging_debugM(true,"ENA:3");
  f_EPTF_Logging_debugV(true,"ENA:4");
  log("Event class 2 is disabled");
  f_EPTF_Logging_disableLocalMask(v_EPTF_Logging_myMaskId, 2);
  f_EPTF_Logging_debug(true,"DIS_CL:2");
  log("Event class 2 is enabled");
  f_EPTF_Logging_enableLocalMask(v_EPTF_Logging_myMaskId, 2);
  f_EPTF_Logging_debug(true,"ENA_CL:2");

}

function f_EPTF_Logging_Test_Generic3() runs on EPTF_Logging_CT {
  f_EPTF_Logging_init_CT("LogTest");

  log ("Logging enabled on component for all features");
  f_EPTF_Logging_debugLevelM(true,"3-4");
  f_EPTF_Logging_debugLevelV(true,"3-5");
  
  log("Event class 1 is disabled");
  f_EPTF_Logging_disableLocalMask(v_EPTF_Logging_myMaskId, 1);
  f_EPTF_Logging_debugLevelM(true,"DIS_CL:3-4");
  f_EPTF_Logging_debugLevelV(true,"DIS_CL:3-5");

  log("Event classes 1 and 2 are disabled");
  f_EPTF_Logging_disableLocalMask(v_EPTF_Logging_myMaskId, 2);
  f_EPTF_Logging_debugLevelM(true,"DIS_CL:3-4");
  f_EPTF_Logging_debugLevelV(true,"DIS_CL:3-5");

  log("Event classes 1 and 2 and 3 are disabled");
  f_EPTF_Logging_disableLocalMask(v_EPTF_Logging_myMaskId, 3);
  f_EPTF_Logging_debugLevelM(true,"DIS_CL:3-4");
  f_EPTF_Logging_debugLevelV(true,"DIS_CL:3-5");
  
  log("Event classes 1 and 3 are disabled");
  f_EPTF_Logging_enableLocalMask(v_EPTF_Logging_myMaskId, 2);
  f_EPTF_Logging_debugLevelM(true,"ENA_CL:3-4");
  f_EPTF_Logging_debugLevelV(true,"ENA_CL:3-5");

}


function f_EPTF_Logging_Test_Generic4() runs on EPTF_Logging_CT {
  f_EPTF_Logging_init_CT("LogTest");

  log ("Logging enabled on component for all features");

  log("Is event class 2 enabled? ",f_EPTF_Logging_isEnabled(v_EPTF_Logging_myMaskId,2));
  log("Is one of event classes 1,2,3 enabled? ",f_EPTF_Logging_isEnabledList(v_EPTF_Logging_myMaskId,{1,2,3}));
  log("Is event class 2 enabled on mask? ",f_EPTF_Logging_maskIsEnabled(v_EPTF_Logging_myMaskId,2));

  log("Event class 2 is disabled");
  f_EPTF_Logging_disableLocalMask(v_EPTF_Logging_myMaskId, 2);

  log("Is event class 2 enabled? ",f_EPTF_Logging_isEnabled(v_EPTF_Logging_myMaskId,2));
  log("Is one of event classes 1,2,3 enabled? ",f_EPTF_Logging_isEnabledList(v_EPTF_Logging_myMaskId,{1,2,3}));
  log("Is event class 2 enabled on mask? ",f_EPTF_Logging_maskIsEnabled(v_EPTF_Logging_myMaskId,2));

  log("Event class 2 is enabled");
  f_EPTF_Logging_enableLocalMask(v_EPTF_Logging_myMaskId, 2);

  log("Is event class 2 enabled? ",f_EPTF_Logging_isEnabled(v_EPTF_Logging_myMaskId,2));
  log("Is one of event classes 1,2,3 enabled? ",f_EPTF_Logging_isEnabledList(v_EPTF_Logging_myMaskId,{1,2,3}));
  log("Is event class 2 enabled on mask? ",f_EPTF_Logging_maskIsEnabled(v_EPTF_Logging_myMaskId,2));
  
  log ("Logging disabled on component for all features");
  f_EPTF_Logging_disableAllLocal();

  log("Is event class 2 enabled? ",f_EPTF_Logging_isEnabled(v_EPTF_Logging_myMaskId,2));
  log("Is one of event classes 1,2,3 enabled? ",f_EPTF_Logging_isEnabledList(v_EPTF_Logging_myMaskId,{1,2,3}));
  log("Is event class 2 enabled on mask? ",f_EPTF_Logging_maskIsEnabled(v_EPTF_Logging_myMaskId,2));
}


function f_EPTF_Logging_Test_Generic5() runs on EPTF_Logging_CT {
  f_EPTF_Logging_init_CT("LogTest");

  var integer v_logMaskIdx;
  v_logMaskIdx := f_EPTF_Logging_registerComponentMasks("EPTF_NewMask", {"Error", "Warning", "Debug"});

  f_EPTF_Logging_log(true,v_logMaskIdx,{0},"0");
  f_EPTF_Logging_log(true,v_logMaskIdx,{1},"1");
  f_EPTF_Logging_log(true,v_logMaskIdx,{2},"2");

  log ("Logging disabled on component for all features");
  f_EPTF_Logging_disableAllLocal();
  f_EPTF_Logging_log(true,v_logMaskIdx,{0},"DIS_ALL:0");
  f_EPTF_Logging_log(true,v_logMaskIdx,{1},"DIS_ALL:1");
  f_EPTF_Logging_log(true,v_logMaskIdx,{2},"DIS_ALL:2");
  log ("Logging enabled on component for all features");
  f_EPTF_Logging_enableAllLocal();
  f_EPTF_Logging_log(true,v_logMaskIdx,{0},"ENA_ALL:0");
  f_EPTF_Logging_log(true,v_logMaskIdx,{1},"ENA_ALL:1");
  f_EPTF_Logging_log(true,v_logMaskIdx,{2},"ENA_ALL:2");
  log ("Logging disabled on component");
  f_EPTF_Logging_disableLocal(v_logMaskIdx);
  f_EPTF_Logging_log(true,v_logMaskIdx,{0},"DIS:0");
  f_EPTF_Logging_log(true,v_logMaskIdx,{1},"DIS:1");
  f_EPTF_Logging_log(true,v_logMaskIdx,{2},"DIS:2");
  log ("Logging enabled on component");
  f_EPTF_Logging_enableLocal(v_logMaskIdx);
  f_EPTF_Logging_log(true,v_logMaskIdx,{0},"ENA:0");
  f_EPTF_Logging_log(true,v_logMaskIdx,{1},"ENA:1");
  f_EPTF_Logging_log(true,v_logMaskIdx,{2},"ENA:2");
  log("Event class 2 is disabled");
  f_EPTF_Logging_disableLocalMask(v_logMaskIdx, 2);
  f_EPTF_Logging_log(true,v_logMaskIdx,{2},"DIS_CL:2");
  log("Event class 2 is enabled");
  f_EPTF_Logging_enableLocalMask(v_logMaskIdx, 2);
  f_EPTF_Logging_log(true,v_logMaskIdx,{2},"ENA_CL:2");

}

function f_EPTF_Logging_preamble1(in charstring pl_message) runs on LogTest_CT 
{
  v_temp := v_temp & "1"; 
}

function f_EPTF_Logging_preamble2(in charstring pl_message) runs on LogTest_CT 
{
  v_temp := v_temp & "2";
}

function f_EPTF_Logging_preamble3(in charstring pl_message) runs on LogTest_CT 
{
  v_temp := v_temp & "3";
}

function f_EPTF_Logging_preamble4(in charstring pl_message) runs on LogTest_CT 
{
  v_temp := v_temp & "4";
}

function f_EPTF_Logging_preambleEmpty(in charstring pl_message) runs on LogTest_CT 
{
}

function f_EPTF_Logging_preambleNotEmpty(in charstring pl_message) runs on LogTest_CT 
{
  v_temp := pl_message;
}


//=========================================================================
// Testcases
//=========================================================================

testcase tc_EPTF_Logging_test1() runs on LogTest_CT {
  log("----------Test1: Checking enable/disable Functions-----------")
  f_EPTF_Logging_Test_Generic1();
  f_EPTF_Base_stop(pass);
}

testcase tc_EPTF_Logging_test2() runs on LogTest_CT {
  log("----------Test2: Checking enable/disable Functions-----------")
  f_EPTF_Logging_Test_Generic2();
  f_EPTF_Base_stop(pass);
}

testcase tc_EPTF_Logging_test3() runs on LogTest_CT {
  log("----------Test4: Checking debugLevelM/V Functions-----------")
  f_EPTF_Logging_Test_Generic3();
  f_EPTF_Base_stop(pass);
}

testcase tc_EPTF_Logging_test4() runs on LogTest_CT {
  log("----------Test3: Checking isEnabled Functions-----------")
  f_EPTF_Logging_Test_Generic4();
  f_EPTF_Base_stop(pass);
}

testcase tc_EPTF_Logging_test5() runs on LogTest_CT {
  log("----------Test4: Checking registering of ComponentMasks-----------")
  f_EPTF_Logging_Test_Generic5();
  f_EPTF_Base_stop(pass);
}

// this is a negative test, which tests if we get the expected error message
testcase tc_EPTF_Logging_errorTest() runs on LogTest_CT {
  f_EPTF_Logging_init_CT("ErrorTest");
  f_EPTF_Base_setNegativeTestMode();
  f_EPTF_Logging_setExpectedErrorMsg("*ErrorMsg1"); // pattern match
  f_EPTF_Logging_error(true,"ErrorMsg1");
  f_EPTF_Logging_error(true,"ErrorMsg2");
  f_EPTF_Logging_checkExpectedError("*ErrorMsg1",0);
  f_EPTF_Logging_checkExpectedError("*ErrorMsg2",1);
  f_EPTF_Base_stopAll(fail);
}

//this is a manual test --> error message should appear in the log
//to test if logging is enabled when EPTF_DEBUG is not switched on
testcase tc_EPTF_Logging_test6() runs on LogTest_CT{
  f_EPTF_Logging_init_CT("test_6");
  f_EPTF_Logging_error(true, "************* Error message! *************");

  //verdict not set here --> check the log
  action("Check the log file to see if the error message is logged!");
  f_EPTF_Base_stop(none);

}

//testcase to test the preamble functions
testcase tc_EPTF_Logging_preamble() runs on LogTest_CT{
  f_EPTF_Logging_init_CT("test_preamble");

  f_EPTF_Logging_registerPreambleFn(refers(f_EPTF_Logging_preamble1));
  f_EPTF_Logging_registerPreambleFn(refers(f_EPTF_Logging_preamble2));
  f_EPTF_Logging_registerPreambleFn(refers(f_EPTF_Logging_preamble3));
  f_EPTF_Logging_registerPreambleFn(refers(f_EPTF_Logging_preamble4));

  f_EPTF_Logging_removePreambleFn(refers(f_EPTF_Logging_preamble2));
  f_EPTF_Logging_removePreambleFn(refers(f_EPTF_Logging_preamble4));

  f_EPTF_Logging_warning(true,"\n\n\n Log to check the preamble functions... \n\n\n");

  if(v_temp == "13")
  {
    f_EPTF_Base_stop(pass);
  }
  else
  {
    setverdict(fail,"v_temp is "&v_temp&" instead of '13'");
    f_EPTF_Base_stop(fail);
  }
}

//testcase to test the lost performance with preamble functions
testcase tc_EPTF_Logging_preamblePerformance() runs on LogTest_CT{
  f_EPTF_Logging_init_CT("test_preamble");

  var float vl_result1 := 0.0;
  var float vl_result2 := 0.0;
  var float vl_result3 := 0.0;
  timer t_timer := 1000.0;

  t_timer.start;
  for(var integer i := 0; i < 100000; i := i + 1)
  {
    f_EPTF_Logging_warning(true,"i: "& int2str(i));
  }
  vl_result1 := t_timer.read;
  t_timer.stop;

  log("\n\n\n elapsed time without registered preample functions: ", vl_result1, "\n\n\n");

  f_EPTF_Logging_registerPreambleFn(refers(f_EPTF_Logging_preambleEmpty));

  t_timer.start;
  for(var integer i := 0; i < 100000; i := i + 1)
  {
    f_EPTF_Logging_warning(true,"i: "& int2str(i));
  }
  vl_result2 := t_timer.read;
  t_timer.stop;

  log("\n\n\n elapsed time with registered empty preample functions: ", vl_result2, "\n\n\n");

  f_EPTF_Logging_removePreambleFn(refers(f_EPTF_Logging_preambleEmpty));
  f_EPTF_Logging_registerPreambleFn(refers(f_EPTF_Logging_preambleNotEmpty));

  t_timer.start;
  for(var integer i := 0; i < 100000; i := i + 1)
  {
    f_EPTF_Logging_warning(true,"i: "& int2str(i));
  }
  vl_result3 := t_timer.read;
  t_timer.stop;

  log("\n\n\n elapsed time with registered preample functions: ", vl_result3, "\n\n\n");

  log("\n\n\n vl_result1: ", vl_result1, "\n vl_result2: ", vl_result2, "\n vl_result3: ", vl_result3, "\n\n\n");
  log("\n\n\n vl_result2 - vl_result1: ", vl_result2 - vl_result1, "\n vl_result3 - vl_result1: ", vl_result3 - vl_result1, "\n\n\n");
  log("\n\n\n % loss in case 2: ", (vl_result2 - vl_result1) / vl_result1 * 100.0, "\n % loss in case 3: ", (vl_result3 - vl_result1) / vl_result1 * 100.0, "\n\n\n");
  
  f_EPTF_Base_stop(none);
}

group EPTF_Logging_Test_lazy {

type component LogTest_Lazy_CT extends LogTest_CT
{
  var boolean v_lazy_check := false;  
}

function f_EPTF_Logging_Test_sideEffect()
  runs on LogTest_Lazy_CT
  return charstring
{
  v_lazy_check := true;
  return "sideffect_test";
}

function f_EPTF_Logging_Test_lazy() runs on LogTest_Lazy_CT {
  f_EPTF_Logging_error(false,"error false "&f_EPTF_Logging_Test_sideEffect());
  if (v_lazy_check) { setverdict(fail, "Side-effect happened with lazy error logging"); }
  
  f_EPTF_Logging_warning(false,"warning false "&f_EPTF_Logging_Test_sideEffect());
  if (v_lazy_check) { setverdict(fail, "Side-effect happened with lazy warning logging"); }
  
  f_EPTF_Logging_debug(false,"debug false "&f_EPTF_Logging_Test_sideEffect());
  if (v_lazy_check) { setverdict(fail, "Side-effect happened with lazy debug logging"); }
  
  f_EPTF_Logging_debugM(false,"debugM false "&f_EPTF_Logging_Test_sideEffect());
  if (v_lazy_check) { setverdict(fail, "Side-effect happened with lazy debugM logging"); }
  
  f_EPTF_Logging_debugV(false,"debugV false "&f_EPTF_Logging_Test_sideEffect());
  if (v_lazy_check) { setverdict(fail, "Side-effect happened with lazy debugV logging"); }
 
  f_EPTF_Logging_warning(true,"warning true "&f_EPTF_Logging_Test_sideEffect());
  if (not v_lazy_check) { setverdict(fail, "Side-effect NOT happened with enabled warning logging"); }
  
} 

testcase tc_EPTF_Logging_Test_lazy() runs on LogTest_Lazy_CT {
  f_EPTF_Logging_init_CT("LogTest");
  log("----------Test_lazy: Checking @lazy parameter evaulation-----------")
  f_EPTF_Logging_Test_lazy();
  f_EPTF_Base_stop(pass);
}

} //group EPTF_Loggin_Test_lazy

//=========================================================================
// Control
//=========================================================================

control 
{
  execute( tc_EPTF_Logging_test1() );
  execute( tc_EPTF_Logging_test2() );
  execute( tc_EPTF_Logging_test3() );
  execute( tc_EPTF_Logging_test4() );
  execute( tc_EPTF_Logging_test5() );
  execute( tc_EPTF_Logging_errorTest() );
  execute( tc_EPTF_Logging_preamble() );
  execute( tc_EPTF_Logging_Test_lazy() );
}

} // end of module