From 3c7ba8c6f48bf8127f42c0c669108cf2ea6901a5 Mon Sep 17 00:00:00 2001 From: StefanStrobel Date: Sat, 9 Jan 2021 19:15:10 +0000 Subject: [PATCH] 98_Modbus: updated tests git-svn-id: https://svn.fhem.de/fhem/trunk@23501 2b470e98-0d58-463d-a4d8-8e2adae1ed80 --- fhem/lib/FHEM/Modbus/TestUtils.pm | 245 +++++++++++++++--------- fhem/t/FHEM/98_Modbus/10_Timer.t | 1 + fhem/t/FHEM/98_Modbus/12_Delays.t | 59 +++--- fhem/t/FHEM/98_Modbus/13_OpenDelays.cfg | 2 +- fhem/t/FHEM/98_Modbus/13_OpenDelays.t | 128 ++++--------- fhem/t/FHEM/98_Modbus/14_QDelay.t | 3 +- fhem/t/FHEM/98_Modbus/31_Register.t | 69 ++----- fhem/t/FHEM/98_Modbus/41_Passive.t | 50 ++--- fhem/t/FHEM/98_Modbus/42_MasterRTU.t | 8 +- fhem/t/FHEM/98_Modbus/50_MasterSlave0.t | 10 - fhem/t/FHEM/98_Modbus/53_Relay.t | 22 +-- fhem/t/FHEM/98_Modbus/54_RelayProto.t | 14 +- fhem/t/FHEM/98_Modbus/58_Profiler.t | 3 +- 13 files changed, 264 insertions(+), 350 deletions(-) diff --git a/fhem/lib/FHEM/Modbus/TestUtils.pm b/fhem/lib/FHEM/Modbus/TestUtils.pm index 3d35b01a7..27ef83f0e 100644 --- a/fhem/lib/FHEM/Modbus/TestUtils.pm +++ b/fhem/lib/FHEM/Modbus/TestUtils.pm @@ -23,7 +23,6 @@ package FHEM::Modbus::TestUtils; use strict; use warnings; - use GPUtils qw(:all); use Time::HiRes qw(gettimeofday); @@ -70,33 +69,37 @@ BEGIN { our $testStep = 0; our %testOptions; our %results; -our $nextStepMode = 'auto'; -sub SimRead { - my $name = shift; - my $readFn = shift; - my $text = shift; - my $option = shift; - my $hash = $defs{$name}; - my $data; - Log3 undef, 1, "Test simulate reception of $text"; - if ($option && $option eq 'ASCII') { - $data = $text; # ascii - } else { - $data = pack ('H*', $text); # hex coded binary - } - $hash->{TestInput} = $data; - eval { &{$readFn}($hash) }; - if ($@) { - Log3 undef, 1, "Test step $testStep call to readFn created error: $@"; - } else { - Log3 undef, 1, "Test step $testStep readFn done."; - } - return; -} +##################################################################### +# +# NextStep +# - GetNextStep +# - set timer for CallStep or end Testing +# +# InternalTimer -> CallStep +# - step via eval +# - NextStep -> Timer for CallStep +# - step via eval +# - NextStep +# +# LogInform -> ReactOnLogRegex -> +# - InternalTimer for SimResponseRead +# +# InternalTimer -> SimResponseRead +# - SimResponseRead +# - NextStep -> Timer for CallStep +# - step via eval +# - send -> LogInform -> SimResponseRead ... +# - NextStep?? (don't set timer for next step in this case) +# + + +################################################################## +# find the next test step number +# internal function, called from NextStep sub GetNextStep { - #Log3 undef, 1, "Test GetNextStep: look for next step"; + Log3 undef, 1, "Test GetNextStep: look for next step"; my $next = $testStep; FINDSTEP: while (1) { @@ -110,43 +113,144 @@ sub GetNextStep { } +###################################################################### +# set internalTimer to call the next test step after an optional delay +# normally in tests to have the first step called and +# also internally by CallStep and SimResponseRead sub NextStep { my $delay = shift // 0; my $next = GetNextStep(); - - InternalTimer(gettimeofday() + $delay, \&CallStep, "main::testStep$next"); - #Log3 undef, 1, "Test NextStep: done."; - $testStep = $next; - return; -} - - -sub CallStep { - my $func = shift; - Log3 undef, 1, "----------------------------------------------------"; - Log3 undef, 1, "Test step $testStep"; - - no strict "refs"; ## no critic - function name needs to be string - my $delay = eval { &{$func}() }; - if ($@) { - Log3 undef, 1, "Test step $testStep call created error: $@"; - } else { - Log3 undef, 1, "Test step $testStep done."; - } - - my $next = GetNextStep(); - if (!$next) { # done if no more steps + if (!$next || ($delay && $delay eq 'end')) { # done if no more steps Log3 undef, 1, "Test NextStep: no more steps found - exiting"; done_testing; exit(0); } - if ($nextStepMode eq 'auto') { - NextStep($delay); # set timer to go to next step with delay returned by last + if (!$delay || $delay ne 'wait') { # set timer to next step unless waiting for reception of data + Log3 undef, 1, "Test NextStep: set timer to call step $next with delay $delay"; + InternalTimer(gettimeofday() + $delay, \&CallStep, "main::testStep$next"); + $testStep = $next; + } + Log3 undef, 1, "Test NextStep: done."; + return; +} + + +############################################################################# +# Call the Test step and then set the timer for the next one +# called by internalTimer +sub CallStep { + my $func = shift; + $func =~ /^(.*[A-Za-z]+)(\d+)$/; + my $step = $2; + Log3 undef, 1, "----------------------------------------------------"; + Log3 undef, 1, "Test step $step ($func)"; + + no strict "refs"; ## no critic - function name needs to be string + my $delay = eval { &{$func}() }; # call the next step and check for errors + if ($@) { + Log3 undef, 1, "Test step $step call created error: $@"; + } else { + Log3 undef, 1, "Test step $step ($func) done, delay before next step is $delay"; + } + # if step function returns 'wait' then do not set timer for next step but wait for ReactOnLogRegex or similar + NextStep($delay); # check for next step and set timer or end testing + return; +} + + +################################################################################ +# check if a regex is found in logs (typically the sending of a request) +# and call SmResponseRead via timer to simulate the reception of a response +# called via logInform +sub ReactOnLogRegex { + my $name = shift; + my $line = shift; + #die "line got: $line"; + if ($line =~ /$testOptions{RespondTo}/) { + my $send = $1; + my $id = substr ($send, 0, 2); + my $recv = $testOptions{ResponseHash}{$send}; # simulate broken error response by default + if (!$recv) { + $recv = ($id . '800041c0'); + Log3 undef, 1, "Test: request $send is not in Reply hash, respond with default error instead"; + } + my $delay = $testOptions{ResponseDelay} // 0.05; + Log3 undef, 1, "------------------------------------------------------------------------"; + Log3 undef, 1, "Test saw sending $send, id $id, set timer to simulate receiving $recv in $delay"; + InternalTimer(gettimeofday() + $delay, \&SimResponseRead, $recv); # set timer to simulate response and go to next step } return; } +####################################################################################### +# simulate the reception of a response by calling SimRead +# and then setting the timer for the next step. +# todo: delay should be definable +sub SimResponseRead { + my $data = shift; + Log3 undef, 1, "Test now simulates reception of response and then checks for next step"; + SimRead($testOptions{IODevice}, $data); + NextStep($testOptions{delayAfterResponse} // 0); + return; +} + + +########################################################################## +# interface to set options hash +# used options: +# - delayAfterResponse : time in seconds to wait after a simualted response before the next step function is called +# - IODevice : name of the device for sending and receiving +# - RespondTo : Regex to be used when monitoring the Fhem log and reacting on a "sending" log with a simulated reception +# - ResponseHash : Hash that maps from data sent (as found in log) to a valid response for the simulation +# - ResponseDelay : delay before the reception of a response is sumulated +# - Time1Regex and Time1Name : name and regex to be searched in log to find the time when it was logged, used by calcDelays +# - Time2Regex and Time2Name : name and regex to be searched in log to find the time when it was logged, used by calcDelays +sub SetTestOptions { + my $opt = shift; + foreach my $k (keys %{$opt}) { + $testOptions{$k} = $opt->{$k}; + } + if ($testOptions{RespondTo}) { + $logInform{$testOptions{IODevice}} = \&ReactOnLogRegex; + } + return; +} + + +############################################################## +# simulate reading from a device. +# the device should be defined with 'none' as interface +# and the readFn should take data from $hash->{TestInput} +# in this case +sub SimRead { + my $name = shift; # Name of the io device that should read data + my $input = shift; # binary input string (coded as hex-string) to be read + my $option = shift; # further otions (so far only 'ASCII' to treat the input string as text instead of hex) + my $hash = $defs{$name}; + my $data; + Log3 undef, 1, "Test simulate reception of $input"; + if ($option && $option eq 'ASCII') { + $data = $input; # ascii + } else { + $data = pack ('H*', $input); # hex coded binary + } + $hash->{TestInput} = $data; + my $type = $defs{$name}{TYPE}; + my $modHash = $modules{$type}; + my $readFn = $modHash->{ReadFn}; + eval { &{$readFn}($hash) }; + if ($@) { + Log3 undef, 1, "Test step $testStep call to readFn created error: $@"; + } else { + Log3 undef, 1, "Test step $testStep readFn done."; + } + return; +} + + +############################################################# +# wrapper for Log3 to be used in tests sub LogStep { my $msg = shift // ''; Log3 undef, 1, "Test step $testStep: $msg"; @@ -154,43 +258,8 @@ sub LogStep { } -sub ReactOnSendingLog { - my $name = shift; - my $line = shift; - #die "line got: $line"; - if ($line =~ /$testOptions{RespondTo}/) { - my $send = $1; - my $id = substr ($send, 0, 2); - my $recv = $testOptions{ReplyHash}{$send} // (($id . '800041c0')); # simulate broken error response by default - my $delay = $testOptions{ResponseDelay} // 0.05; - Log3 undef, 1, "------------------------------------------------------------------------"; - Log3 undef, 1, "Test saw sending $send, id $id, set timer to simulate receiving $recv in $delay"; - InternalTimer(gettimeofday() + $delay, \&SimResponseRead, $recv); - } - return; -} - - -sub SimResponseRead { - my $data = shift; - Log3 undef, 1, "Test now simulate reception of response and then call next step"; - SimRead($testOptions{IODevice}, $testOptions{ReadFn}, $data); - NextStep(); -} - - -sub SetTestOptions { - my $opt = shift; - foreach my $k (keys %{$opt}) { - $testOptions{$k} = $opt->{$k}; - } - if ($testOptions{RespondTo}) { - $nextStepMode = 'reception'; - $logInform{$testOptions{IODevice}} = \&ReactOnSendingLog; - } -} - - +########################################################################### +# find the time of two regexes in the log sub findTimesInLog { $results{$testOptions{Time1Name}.$testStep} = FhemTestUtils_getLogTime($testOptions{Time1Regex}); $results{$testOptions{Time2Name}.$testStep} = FhemTestUtils_getLogTime($testOptions{Time2Regex}); @@ -202,6 +271,8 @@ sub findTimesInLog { } +################################################################################ +# calculate and log the time differences found by calling findTimesInLog sub calcDelays { my ($lastDelay, $commDelay, $sendDelay); if (defined ($results{$testOptions{Time1Name} . $testStep}) && diff --git a/fhem/t/FHEM/98_Modbus/10_Timer.t b/fhem/t/FHEM/98_Modbus/10_Timer.t index e4d63d89d..01ca5cb7a 100644 --- a/fhem/t/FHEM/98_Modbus/10_Timer.t +++ b/fhem/t/FHEM/98_Modbus/10_Timer.t @@ -1,6 +1,7 @@ ############################################## # test update timer ############################################## +package main; use strict; use warnings; use Test::More; diff --git a/fhem/t/FHEM/98_Modbus/12_Delays.t b/fhem/t/FHEM/98_Modbus/12_Delays.t index 137f7cb5a..2cee59f0c 100644 --- a/fhem/t/FHEM/98_Modbus/12_Delays.t +++ b/fhem/t/FHEM/98_Modbus/12_Delays.t @@ -1,5 +1,5 @@ ############################################## -# test request parsing +# test communication delays ############################################## package main; use strict; @@ -35,20 +35,19 @@ my %rData = ( fhem 'attr global mseclog 1'; SetTestOptions( - { IODevice => 'MS', # for loginform - RespondTo => 'MS: Simulate sending to none: (.*)', # auto reponder / go to next step at reception - ReadFn => \&Modbus::ReadFn, # call for reception - ReplyHash => \%rData, # to find the right response + { IODevice => 'MS', # for loginform + RespondTo => 'MS: Simulate sending to none: (.*)', # auto reponder / go to next step at reception + ResponseHash => \%rData, # to find the right response - Time1Name => 'Sending', - Time1Regex => qr{MS:\sSimulate\ssending}, - Time2Name => 'Reception', - Time2Regex => qr{ParseFrameStart\s\(RTU\)\sextracted\sid}, + Time1Name => 'Sending', + Time1Regex => qr{MS:\sSimulate\ssending}, + Time2Name => 'Reception', + Time2Regex => qr{ParseFrameStart\s\(RTU\)\sextracted\sid}, } ); -fhem 'get M1 SolarTemp'; +fhem 'get M1 SolarTemp'; # will cause step 1 to be called when send is detected and response is simulated sub testStep1 { findTimesInLog(); @@ -59,7 +58,7 @@ sub testStep1 { fhem 'get M1 HeatOff'; # read simulation is triggered when sending is seen in the log. # next step is called when read simulation is done. - return; + return 'wait'; } @@ -73,7 +72,7 @@ sub testStep2 { fhem 'attr M1 dev-timing-sendDelay 0.2'; # send in step2 should be 0.2 after send in step1 fhem 'get M1 HeatOff'; - return; + return 'wait'; } @@ -84,10 +83,10 @@ sub testStep3 { # check send delay between read (get HeatOff) after Step 1 and send (get HeatOff) in step 2 ok($sendDelay >= 0.2, 'defined send delay from read HeatOff to next send get HeatOff big enough'); - ok($sendDelay < 0.22, 'defined send delay from read HeatOff to next send get HeatOff not too big'); + ok($sendDelay < 0.25, 'defined send delay from read HeatOff to next send get HeatOff not too big'); fhem 'get M5 TempWasserEin'; - return; + return 'wait'; } @@ -97,11 +96,11 @@ sub testStep4 { my ($commDelay, $sendDelay) = calcDelays(); # check no send delay between read (get HeatOff) after Step 2 and send (get TempWasserEin to id 5) in step 3 - ok($sendDelay < 0.1, 'defined send delay on id 1 from read HeatOff to send get TempWasserEin not used for id 5'); + ok($sendDelay < 0.15, 'defined send delay on id 1 from read HeatOff to send get TempWasserEin not used for id 5'); fhem 'attr MS busDelay 0.2'; - fhem 'get M5 TempWasserAus'; - return; + fhem 'get M5 TempWasserAus'; # new request, go to next step when response is simulated + return 'wait'; } @@ -117,8 +116,8 @@ sub testStep5 { fhem 'attr MS busDelay 0'; fhem 'attr M1 dev-timing-sendDelay 0'; fhem 'attr MS clientSwitchDelay 0'; - fhem 'get M1 SolarTemp'; - return; + fhem 'get M1 SolarTemp'; # new request, go to next step when response is simulated + return 'wait'; } @@ -129,8 +128,8 @@ sub testStep6 { ok($sendDelay < 0.2, 'no delay'); fhem 'attr MS clientSwitchDelay 0.2'; - fhem 'get M5 TempWasserEin'; - return; + fhem 'get M5 TempWasserEin'; # new request, go to next step when response is simulated + return 'wait'; } @@ -142,8 +141,8 @@ sub testStep7 { ok($commDelay >= 0.2, 'defined clsw delay big enough'); ok($commDelay < 0.3, 'defined clsw delay not too big'); - fhem 'get M5 TempWasserAus'; - return; + fhem 'get M5 TempWasserAus'; # new request, go to next step when response is simulated + return 'wait'; } @@ -152,11 +151,11 @@ sub testStep8 { FhemTestUtils_resetLogs(); my ($commDelay, $sendDelay) = calcDelays(); - ok($sendDelay < 0.1, 'no delay for same id'); + ok($sendDelay < 0.2, 'no delay for same id'); fhem 'attr M5 dev-timing-commDelay 0.2'; - fhem 'get M5 TempWasserEin'; - return; + fhem 'get M5 TempWasserEin'; # new request, go to next step when response is simulated + return 'wait'; } @@ -169,8 +168,8 @@ sub testStep9 { ok($commDelay < 0.22, 'defined comm delay not too big'); fhem 'attr M5 dev-timing-commDelay 0'; - fhem 'get M5 TempWasserEin'; - return; + fhem 'get M5 TempWasserEin'; # new request, go to next step when response is simulated + return 'wait'; } @@ -183,8 +182,8 @@ sub testStep10 { fhem 'attr M5 dev-timing-commDelay 0.2'; fhem 'attr M5 verbose 4'; - fhem 'set M5 o1 on'; - return; + fhem 'set M5 o1 on'; # new request, go to next step when response is simulated + return 'wait'; } diff --git a/fhem/t/FHEM/98_Modbus/13_OpenDelays.cfg b/fhem/t/FHEM/98_Modbus/13_OpenDelays.cfg index 14330da85..aff244bf4 100644 --- a/fhem/t/FHEM/98_Modbus/13_OpenDelays.cfg +++ b/fhem/t/FHEM/98_Modbus/13_OpenDelays.cfg @@ -4,7 +4,7 @@ define D1 dummy define Slave ModbusAttr 5 slave global:5501 attr Slave obj-h256-reading TempWasserEin -attr Slave obj-h258-reading D1:TempWasserAus +attr Slave obj-h258-reading TempWasserAus attr Slave obj-h100-reading Test1 attr Slave obj-h100-setexpr $val * 4 diff --git a/fhem/t/FHEM/98_Modbus/13_OpenDelays.t b/fhem/t/FHEM/98_Modbus/13_OpenDelays.t index f7ca62bc1..482ec4ee8 100644 --- a/fhem/t/FHEM/98_Modbus/13_OpenDelays.t +++ b/fhem/t/FHEM/98_Modbus/13_OpenDelays.t @@ -1,7 +1,5 @@ ############################################## -# test master slave end to end -# attr disable -# and set inactive / set active +# test open delays ############################################## package main; use strict; @@ -9,14 +7,14 @@ use warnings; use Test::More; use Time::HiRes qw( gettimeofday tv_interval); # return time as float, not just full seconds use FHEM::HTTPMOD::Utils qw(:all); +use FHEM::Modbus::TestUtils qw(:all); use Data::Dumper; my $closeTime; my $openTime; my $startTime; -InternalTimer(gettimeofday() + 0.1, "testStep1", 0); - +NextStep(); sub getLogTime { my $regex = shift; @@ -27,51 +25,42 @@ sub getLogTime { return $time; } - sub testStep1 { # preparation of slave content, enable devices - Log3 undef, 1, "----------------"; #is(FhemTestUtils_gotLog('attribute'), 0, "no unknown attributes"); # logs during init are not collected. - Log3 undef, 1, "TestStep1: enable Master and set value at Slave"; + LogStep "TestStep1: enable Master and set value at Slave"; fhem ('attr Master disable 0'); fhem ('setreading Slave TempWasserEin 12'); + fhem ('setreading Slave TempWasserAus 23'); fhem ('setreading Slave Test1 1'); fhem ('setreading Slave Test2 2.123'); fhem ('setreading Slave Test3 abcdefg'); fhem ('setreading Slave Test4 40'); - - InternalTimer(gettimeofday() + 0.1, "testStep2", 0); + return 0.1; } sub testStep2 { # get holding registers - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep2: get TempWasserEin"; fhem ('attr Master verbose 5'); fhem ('attr Slave verbose 3'); fhem ('get Master TempWasserEin'); - InternalTimer(gettimeofday() + 0.1, "testStep3", 0); + return 0.1; } sub testStep3 { # check first result, disable and request again - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep3: check result, disable master and request again"; is(FhemTestUtils_gotEvent(qr/Master:TempWasserEin:\s12/xms), 1, "Retrieve integer value from local slave"); FhemTestUtils_resetEvents(); FhemTestUtils_resetLogs(); fhem ('attr Master disable 1'); fhem ('get Master TempWasserEin'); - - InternalTimer(gettimeofday(), "testStep4", 0); + return; } sub testStep4 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep4: check that master disable worked"; is(FhemTestUtils_gotEvent(qr/Master:TempWasserEin:\s12/xms), 0, "no Retrieve for disabled"); is(FhemTestUtils_gotEvent(qr/Master:disabled/xms), 1, "state disabled"); fhem ('attr Master disable 0'); FhemTestUtils_resetEvents(); FhemTestUtils_resetLogs(); - InternalTimer(gettimeofday() + 0.1, "testStep5", 0); + return 0.1; } sub testStep5 { @@ -80,44 +69,38 @@ sub testStep5 { $startTime = getLogTime ('Master device opened'); fhem ('attr Master enableSetInactive 1'); fhem ('set Master inactive'); - InternalTimer(gettimeofday(), "testStep6", 0); + return; } sub testStep6 { Log3 undef, 1, "----------------"; Log3 undef, 1, "TestStep6: now try to get reading again"; fhem ('get Master TempWasserEin'); - InternalTimer(gettimeofday(), "testStep7a", 0); + return; } -sub testStep7a { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep7a: check if reading was not requested and then set master to active again"; +sub testStep7 { is(FhemTestUtils_gotEvent(qr/Master:TempWasserEin:\s12/xms), 0, "no Retrieve for inactive"); FhemTestUtils_resetEvents(); FhemTestUtils_resetLogs(); fhem ('attr Master nextOpenDelay2 0'); # don't wait with open fhem ('set Master active'); - InternalTimer(gettimeofday(), "testStep7b", 0); + return; } -sub testStep7b { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep7b: try retrieve again"; +sub testStep8 { $openTime = getLogTime ('Master device opened'); - Log3 undef, 1, "TestStep7b: Time diff is " . sprintf ('%.3f', $openTime - $startTime); + Log3 undef, 1, "Test: Time diff is " . sprintf ('%.3f', $openTime - $startTime); ok($openTime - $startTime < 0.25, 'time between two open calls is smaller than 0.25'); FhemTestUtils_resetEvents(); FhemTestUtils_resetLogs(); - fhem ('get Master TempWasserEin'); - InternalTimer(gettimeofday() + 0.1, "testStep8", 0); + fhem ('get Master TempWasserAus'); + return 0.2; } -sub testStep8 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep8: check result and then set slave to inactive and try again"; - is(FhemTestUtils_gotEvent(qr/Master:TempWasserEin:\s12/xms), 1, "Retrieve integer value again from local slave"); +sub testStep9 { + is(FhemTestUtils_gotEvent(qr/Master:TempWasserAus:\s23/xms), 1, "Retrieve integer value again from local slave"); fhem ('set Slave inactive'); FhemTestUtils_resetEvents(); FhemTestUtils_resetLogs(); @@ -126,94 +109,53 @@ sub testStep8 { fhem ('attr Master nextOpenDelay2 0.1'); # fhem ('attr Master nextOpenDelay 1'); # can not be smaller than 1 fhem ('get Master TempWasserEin'); # should run into timeout - InternalTimer(gettimeofday()+0.5, "testStep8b", 0); + return 0.5; } -sub testStep8b { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep8b: check that request was not answered and get last open time"; +sub testStep10 { is(FhemTestUtils_gotEvent(qr/Master:TempWasserEin:\s12/xms), 0, "no Retrieve for inactive Slave"); #is(FhemTestUtils_gotLog('Master: Timeout waiting for a modbus response'), 1, "saw timeout"); $startTime = getLogTime ('HttpUtils url=http://localhost:5501'); # time of first try fhem ('set Slave active'); - InternalTimer(gettimeofday()+1, "testStep8c", 0); + return 1.0; } -sub testStep8c { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep8c: "; - InternalTimer(gettimeofday()+1, "testStep9a", 0); +sub testStep11 { + return 1.0; } -sub testStep9a { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep9a: check nextOpenDelay"; +sub testStep12 { $openTime = getLogTime ('5501 reappeared'); - Log3 undef, 1, "TestStep7b: Time diff is " . sprintf ('%.3f', $openTime - $startTime); + Log3 undef, 1, "TestStep12: Time diff is " . sprintf ('%.3f', $openTime - $startTime); ok($openTime - $startTime >= 1, 'time between two open calls is bigger than 1'); ok($openTime - $startTime < 2, 'time between two open calls is smaller than 2'); - InternalTimer(gettimeofday() + 0.1, "testStep9b", 0); + return 0.1; } -sub testStep9b { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep9b: "; - InternalTimer(gettimeofday(), "testStep9c", 0); +sub testStep13 { + return; } -sub testStep9c { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep9b: retrieve value and then let Slave close after inactivity timeout"; +sub testStep14 { # now open should happen and event should come fhem('attr Slave dev-timing-serverTimeout 1'); fhem('attr Slave dev-timing-serverTimeout 1'); FhemTestUtils_resetEvents(); FhemTestUtils_resetLogs(); fhem ('get Master TempWasserEin'); - InternalTimer(gettimeofday() + 1.1, "testStep10", 0); + return 1.1; } -sub testStep10 { +sub testStep15 { # check that we now got the value - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep10: check successful retrieve after slave is active again and master did open connection"; is(FhemTestUtils_gotEvent(qr/Master:TempWasserEin:\s12/xms), 1, "Retrieve integer value again from local slave"); - InternalTimer(gettimeofday() + 0.5, "testStep11", 0); + return 0.5; } -sub testStep11 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep11:"; - InternalTimer(gettimeofday() + 1, "testStep12", 0); +sub testStep16 { + return; } -sub testStep12 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep12:"; - InternalTimer(gettimeofday() + 1, "testStep13", 0); -} - -sub testStep13 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep13:"; - InternalTimer(gettimeofday(), "testStepEnd", 0); -} - - -sub testStepX { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStepX: "; - #fhem ('get '); - InternalTimer(gettimeofday() + 0.1, "testStepEnd", 0); -} - - -sub testStepEnd { - done_testing; - exit(0); -} - - 1; diff --git a/fhem/t/FHEM/98_Modbus/14_QDelay.t b/fhem/t/FHEM/98_Modbus/14_QDelay.t index be2e428e7..6b5531a08 100644 --- a/fhem/t/FHEM/98_Modbus/14_QDelay.t +++ b/fhem/t/FHEM/98_Modbus/14_QDelay.t @@ -1,5 +1,5 @@ ############################################## -# test request parsing +# test queue delays ############################################## use strict; use warnings; @@ -13,7 +13,6 @@ fhem 'attr global mseclog 1'; SetTestOptions( { IODevice => 'MS', # for loginform - #RespondTo => 'MS: Simulate sending to none: (.*)', # auto reponder / go to next step at reception Time1Name => 'busy', Time1Regex => qr{Fhem is still waiting}, Time2Name => 'queue run', diff --git a/fhem/t/FHEM/98_Modbus/31_Register.t b/fhem/t/FHEM/98_Modbus/31_Register.t index f679602f6..ea98fa425 100644 --- a/fhem/t/FHEM/98_Modbus/31_Register.t +++ b/fhem/t/FHEM/98_Modbus/31_Register.t @@ -1,6 +1,5 @@ ############################################## -# test master slave end to end -# attr disable +# test attr disable # and set inactive / set active ############################################## use strict; @@ -8,102 +7,62 @@ use warnings; use Test::More; use Time::HiRes qw(gettimeofday tv_interval); # return time as float, not just full seconds use FHEM::HTTPMOD::Utils qw(:all); +use FHEM::Modbus::TestUtils qw(:all); use Data::Dumper; -InternalTimer(gettimeofday() + 0.1, "testStep1", 0); +NextStep(); + sub testStep1 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep1: define Master over MS"; - fhem ('define Master ModbusAttr 5 0'); - InternalTimer(gettimeofday() + 0.1, "testStep2", 0); + return 0.1; } sub testStep2 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep2: "; is(FhemTestUtils_gotLog('registers Master at MS with id 5, MODE master, PROTOCOL RTU'), 1, "Master registered"); fhem ('define Master2 ModbusAttr 4 0'); - InternalTimer(gettimeofday() + 0.1, "testStep3", 0); + return 0.1; } sub testStep3 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep3: "; is(FhemTestUtils_gotLog('registers Master2 at MS with id 4, MODE master, PROTOCOL RTU'), 1, "Master2 registered"); fhem ('define Master3 ModbusAttr 4 0 ASCII'); fhem ('attr Master3 enableSetInactive 1'); fhem ('attr Master3 verbose 5'); fhem ('attr Master3 obj-h100-reading test'); fhem ('attr Master3 obj-h100-showGet 1'); - InternalTimer(gettimeofday() + 0.1, "testStep4", 0); + return 0.1; } sub testStep4 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep4: "; is(FhemTestUtils_gotLog('Master3: SetIODev found no usable physical modbus device'), 1, "No IODev for Master3 (MS already locked as RTU)"); FhemTestUtils_resetLogs(); fhem ('attr Master disable 1'); fhem ('get Master3 test'); - InternalTimer(gettimeofday() + 0.1, "testStep5", 0); + return 0.1; } + sub testStep5 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep5: "; is(FhemTestUtils_gotLog('Master3: SetIODev found no usable physical modbus device'), 1, "No IODev for Master3 (MS still locked as RTU)"); FhemTestUtils_resetLogs(); fhem ('attr Master2 disable 1'); fhem ('get Master3 test'); - InternalTimer(gettimeofday() + 0.1, "testStep6", 0); + return 0.1; } + sub testStep6 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep6: "; is(FhemTestUtils_gotLog('registers Master3 at MS with id 4, MODE master, PROTOCOL ASCII'), 1, "Now MS is locked as ASCII"); FhemTestUtils_resetLogs(); fhem ('define Slave1 ModbusAttr 10 slave ASCII'); - InternalTimer(gettimeofday() + 0.1, "testStep7", 0); + return 0.1; } + sub testStep7 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep7: "; is(FhemTestUtils_gotLog('Slave1: SetIODev found no usable physical modbus device'), 1, "no io device for slave"); fhem ('delete Slave1'); fhem ('attr Master3 disable 1'); fhem ('define Slave1 ModbusAttr 10 slave ASCII'); - InternalTimer(gettimeofday() + 0.1, "testStep8", 0); + return 0.1; } -sub testStep8 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep8: "; - is(FhemTestUtils_gotLog('registers Slave1 at MS with id 10, MODE slave, PROTOCOL ASCII'), 1, "now slave can use MS as IO Device"); - InternalTimer(gettimeofday() + 0.1, "testStep9", 0); -} -sub testStep9 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep9: "; - InternalTimer(gettimeofday() + 0.1, "testStep10", 0); -} -sub testStep10 { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStep10: "; - InternalTimer(gettimeofday() + 0.1, "testStepEnd", 0); -} - -sub testStepX { - Log3 undef, 1, "----------------"; - Log3 undef, 1, "TestStepX: "; - #fhem ('get '); - InternalTimer(gettimeofday() + 0.1, "testStepEnd", 0); -} - - -sub testStepEnd { - done_testing; - exit(0); -} - 1; diff --git a/fhem/t/FHEM/98_Modbus/41_Passive.t b/fhem/t/FHEM/98_Modbus/41_Passive.t index 6486197bb..00fd5b853 100644 --- a/fhem/t/FHEM/98_Modbus/41_Passive.t +++ b/fhem/t/FHEM/98_Modbus/41_Passive.t @@ -11,56 +11,28 @@ use Time::HiRes qw( gettimeofday tv_interval); # return time as flo use FHEM::HTTPMOD::Utils qw(:all); use FHEM::Modbus::TestUtils qw(:all); -#$logInform{'MS'} = \&ReactOnSendingLog; - -my @rData = ( - - '05030100000585b1', # request h 256 - h 260 (TempWasserEin, TempWasserAus) - '05030a0137110001381100010dac7b', # response - - '0503010600016473', # request h 262 - '0503020106c816', # response - - '050303020001240a', # request h 770 - '0503020122c80d', # response - - '05030309000155c8', # request - '05030200004984', # response - - '0503010000018472', - '050302013709c2', # response - - '0506030900005808', # request set hyst mode - '0506030900005808', # response - - '0506030201182850', # request set temp soll 28 - '0506030201182850' # response -); -my $dataPtr = 0; - fhem 'attr global mseclog 1'; -InternalTimer(gettimeofday()+5, "testStepLast", 0); # last resort NextStep(); sub testStep1 { LogStep "send first request in parts"; FhemTestUtils_resetLogs(); - SimRead('MS', \&Modbus::ReadFn, 'fe03'); # part of a request + SimRead('MS', 'fe03'); # part of a request return; } sub testStep2 { FhemTestUtils_resetLogs(); - SimRead('MS', \&Modbus::ReadFn, '0164000810'); # part of a request + SimRead('MS', '0164000810'); # part of a request return; } sub testStep3 { FhemTestUtils_resetLogs(); - SimRead('MS', \&Modbus::ReadFn, '20'); # final part of a request + SimRead('MS', '20'); # final part of a request return; } @@ -70,18 +42,18 @@ sub testStep4 { is(FhemTestUtils_gotLog('received valid request, now wait for the reponse'), 1, "first request reassembled correctly"); FhemTestUtils_resetLogs(); FhemTestUtils_resetEvents(); - SimRead('MS', \&Modbus::ReadFn, 'fe03016400081020'); # another request + SimRead('MS', 'fe03016400081020'); # another request return; } sub testStep5 { LogStep "check reception of repeated request and send first reply"; - is(FhemTestUtils_gotLog('no valid response -> try interpretation as request instead'), 1, "invalid respone and switch to request"); + is(FhemTestUtils_gotLog('no valid response -> try interpretation as request instead'), 1, "corectly detected invalid respone and switch to request"); is(FhemTestUtils_gotLog('received valid request, now wait for the reponse'), 1, "second request interpreted"); FhemTestUtils_resetLogs(); FhemTestUtils_resetEvents(); - SimRead('MS', \&Modbus::ReadFn,'fe03100000000b000000400000011a00000167f378'); # the reply + SimRead('MS', 'fe03100000000b000000400000011a00000167f378'); # the reply return; } @@ -91,7 +63,7 @@ sub testStep6 { is(FhemTestUtils_gotLog('ParseObj has no information about handling h356'), 1, "try parsing registers"); FhemTestUtils_resetLogs(); FhemTestUtils_resetEvents(); - SimRead('MS', \&Modbus::ReadFn,'fe03100000000b000000400000011a00000167f378'); # the reply repeated + SimRead('MS', 'fe03100000000b000000400000011a00000167f378'); # the reply repeated return; } @@ -102,7 +74,7 @@ sub testStep7 { is(FhemTestUtils_gotLog('HandleResponse got data but we don.t have a request'), 1, "next response without a request seen"); FhemTestUtils_resetLogs(); FhemTestUtils_resetEvents(); - SimRead('MS', \&Modbus::ReadFn, 'fe03064000810209'); # a broken frame + SimRead('MS', 'fe03064000810209'); # a broken frame return; } @@ -110,7 +82,7 @@ sub testStep7 { sub testStep8 { is(FhemTestUtils_gotLog('HandleRequest Done, error: '), 1, "invalid frame"); FhemTestUtils_resetLogs(); - SimRead('MS', \&Modbus::ReadFn, 'fe03016400081020'); # another request + SimRead('MS', 'fe03016400081020'); # another request return; } @@ -125,7 +97,7 @@ sub testStep10 { LogStep "check broken frame with illegal fcode"; FhemTestUtils_resetLogs(); FhemTestUtils_resetEvents(); - SimRead('MS', \&Modbus::ReadFn, 'fe00064000810209'); # a broken frame + SimRead('MS', 'fe00064000810209'); # a broken frame return; } @@ -133,7 +105,7 @@ sub testStep10 { sub testStep11 { is(FhemTestUtils_gotLog('HandleRequest Done, error:'), 1, "invalid frame"); FhemTestUtils_resetLogs(); - SimRead('MS', \&Modbus::ReadFn, 'fe03016400081020'); # another request + SimRead('MS', 'fe03016400081020'); # another request return; } diff --git a/fhem/t/FHEM/98_Modbus/42_MasterRTU.t b/fhem/t/FHEM/98_Modbus/42_MasterRTU.t index 88cc6e7b3..8f6a9a3d9 100644 --- a/fhem/t/FHEM/98_Modbus/42_MasterRTU.t +++ b/fhem/t/FHEM/98_Modbus/42_MasterRTU.t @@ -25,7 +25,7 @@ sub testStep1 { sub testStep2 { LogStep('simulate normal reception'); - SimRead('MS', \&Modbus::ReadFn, '05030a0137110001381100010dac7b'); # normal response + SimRead('MS', '05030a0137110001381100010dac7b'); # normal response return; } @@ -44,7 +44,7 @@ sub testStep3 { sub testStep4 { LogStep('simulate short response'); - SimRead('MS', \&Modbus::ReadFn, '05030a013711000138110091a8'); # short response + SimRead('MS', '05030a013711000138110091a8'); # short response return 1.1; # next step after 1.1 seconds } @@ -64,7 +64,7 @@ sub testStep5 { sub testStep6 { LogStep('simulate another short response'); - SimRead('MS', \&Modbus::ReadFn, '05030a013711000138110091a8'); # short response + SimRead('MS', '05030a013711000138110091a8'); # short response return; } @@ -85,7 +85,7 @@ sub testStep7 { sub testStep8 { LogStep('simulate broken fc3 response'); - SimRead('MS', \&Modbus::ReadFn, '050301000137110001381100010dd04d'); # response type broken FC3 + SimRead('MS', '050301000137110001381100010dd04d'); # response type broken FC3 return; } diff --git a/fhem/t/FHEM/98_Modbus/50_MasterSlave0.t b/fhem/t/FHEM/98_Modbus/50_MasterSlave0.t index a9682890d..72f85a713 100644 --- a/fhem/t/FHEM/98_Modbus/50_MasterSlave0.t +++ b/fhem/t/FHEM/98_Modbus/50_MasterSlave0.t @@ -12,7 +12,6 @@ use FHEM::HTTPMOD::Utils qw(:all); use FHEM::Modbus::TestUtils qw(:all); fhem 'attr global mseclog 1'; -InternalTimer(gettimeofday()+5, "testStepLast", 0); # last resort NextStep(); sub testStep1 { # preparation of slave content, enable devices @@ -219,13 +218,4 @@ sub testStep21 { return; } - -# todo: different protocols (RTU, ASCII, TCP) -# data type definition -# swap bytes and similar -# unpack variations - -# then relay mode - - 1; diff --git a/fhem/t/FHEM/98_Modbus/53_Relay.t b/fhem/t/FHEM/98_Modbus/53_Relay.t index a2cb842cd..aa0a2bab8 100644 --- a/fhem/t/FHEM/98_Modbus/53_Relay.t +++ b/fhem/t/FHEM/98_Modbus/53_Relay.t @@ -1,5 +1,5 @@ ############################################## -# test master slave end to end +# test relay ############################################## package main; @@ -12,7 +12,6 @@ use FHEM::HTTPMOD::Utils qw(:all); use FHEM::Modbus::TestUtils qw(:all); fhem 'attr global mseclog 1'; -InternalTimer(gettimeofday()+5, "testStepLast", 0); # last resort NextStep(); sub testStep1 { # preparation of slave content, enable devices @@ -108,7 +107,7 @@ sub testStep9 { # check write data is(FhemTestUtils_gotLog('0506000a0001698c'), 1, "set o1 on message in log"); is(FhemTestUtils_gotLog('0506000b0002784d'), 1, "set O2 2 message in log"); fhem ('attr Master verbose 3'); - return 0.1; + return 0.2; } @@ -116,7 +115,7 @@ sub testStep10 { # check combined read of holding registers and coils LogStep "getUpdate with combine"; FhemTestUtils_resetEvents(); fhem ('set Master reread'); - return 0.1; + return 0.2; } sub testStep11 { # check results coming from slave and write coils to slave @@ -129,8 +128,9 @@ sub testStep11 { # check results coming from slave and write coils to slave fhem ('attr Slave obj-c402-allowWrite 1'); fhem ('attr Master verbose 5'); + #fhem ('attr Slave verbose 5'); # todo: remove fhem ('set Master c2 1'); - return 0.1; + return 0.2; } sub testStep12 { @@ -144,7 +144,7 @@ sub testStep12 { fhem ('attr Slave verbose 3'); fhem ('attr Master dev-h-write 16'); fhem ('set Master TempWasserAus 29'); - return 0.1; + return 0.2; } sub testStep13 { @@ -160,7 +160,7 @@ sub testStep14 { fhem ('attr Master closeAfterResponse 1'); fhem ('attr Master verbose 4'); fhem ('set Master reread'); - return 0.1; + return 0.2; } sub testStep15 { @@ -219,12 +219,4 @@ sub testStep21 { } -# todo: different protocols (RTU, ASCII, TCP) -# data type definition -# swap bytes and similar -# unpack variations - -# then relay mode - - 1; diff --git a/fhem/t/FHEM/98_Modbus/54_RelayProto.t b/fhem/t/FHEM/98_Modbus/54_RelayProto.t index a2cb842cd..43e1272d7 100644 --- a/fhem/t/FHEM/98_Modbus/54_RelayProto.t +++ b/fhem/t/FHEM/98_Modbus/54_RelayProto.t @@ -1,5 +1,5 @@ ############################################## -# test master slave end to end +# test relay with different protocols ############################################## package main; @@ -12,7 +12,6 @@ use FHEM::HTTPMOD::Utils qw(:all); use FHEM::Modbus::TestUtils qw(:all); fhem 'attr global mseclog 1'; -InternalTimer(gettimeofday()+5, "testStepLast", 0); # last resort NextStep(); sub testStep1 { # preparation of slave content, enable devices @@ -116,7 +115,7 @@ sub testStep10 { # check combined read of holding registers and coils LogStep "getUpdate with combine"; FhemTestUtils_resetEvents(); fhem ('set Master reread'); - return 0.1; + return 0.2; } sub testStep11 { # check results coming from slave and write coils to slave @@ -218,13 +217,4 @@ sub testStep21 { return; } - -# todo: different protocols (RTU, ASCII, TCP) -# data type definition -# swap bytes and similar -# unpack variations - -# then relay mode - - 1; diff --git a/fhem/t/FHEM/98_Modbus/58_Profiler.t b/fhem/t/FHEM/98_Modbus/58_Profiler.t index 2cb4a1907..c5b2f0052 100644 --- a/fhem/t/FHEM/98_Modbus/58_Profiler.t +++ b/fhem/t/FHEM/98_Modbus/58_Profiler.t @@ -1,5 +1,5 @@ ############################################## -# test master slave end to end +# test profiler (to be implemented!) ############################################## package main; @@ -12,7 +12,6 @@ use FHEM::HTTPMOD::Utils qw(:all); use FHEM::Modbus::TestUtils qw(:all); fhem 'attr global mseclog 1'; -InternalTimer(gettimeofday()+5, "testStepLast", 0); # last resort NextStep(); sub testStep1 { # preparation of slave content, enable devices