Re: [v3][libgpiod][PATCH 1/1] gpio-tools-test.bats: modify delays in toggle test

[Bartosz Golaszewski <brgl@xxxxxxxx>]

On Tue, Jun 6, 2023 at 5:12 PM Bartosz Golaszewski <brgl@xxxxxxxx> wrote:
>
> On Tue, Jun 6, 2023 at 5:11 PM Slater, Joseph <joe.slater@xxxxxxxxxxxxx> wrote:
> >
> > I finally (I hope) got rid of the "sleep" comment.
> >
> > I have not used bats before, but I gather that the bats file will get parsed 160 times since you have 159 tests.  Breaking the file up into pieces might help, but that's only a guess.  For me, the bats tests take about 4 minutes in qemu.
> >
> > Joe
> >
>
> FYI, I've opened an issue[1] on bats-core github as strace output for
> -c -f switches was right after all.
>
> Bart
>
> [1] https://github.com/bats-core/bats-core/issues/733
>

I'm afraid this is just how bats works - I'm getting similar output
when running bats' own test-suite:

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ------------------
 94,78   87,937096        2697     32603     14298 wait4
  1,20    1,117514           0   1695481           rt_sigprocmask
  1,09    1,008525           0   1045150        27 read
  0,66    0,608701          36     16741           clone
  0,48    0,441647          11     37725     23464 execve
  0,21    0,199233           0    274617    107718 newfstatat
  0,20    0,182347           1     98627      4962 openat
  0,18    0,165625           0    169950           mmap
  0,15    0,134789           0    184782    162361 ioctl
  0,14    0,129233           3     40735           write
  0,12    0,113985           0    198739      4196 close
  0,10    0,095850           0    139639      3159 fcntl
  0,09    0,086048           0    312173           rt_sigaction
  0,08    0,070505           0     95010     34204 lseek
  0,06    0,053366           0     56400           dup2
  0,06    0,052509           1     51470           mprotect
  0,05    0,045429           7      5704      3457 mkdir

When the tests are running, bats spawns a tree of 6 subprocesses for
every test-case and each parent waits for its child to exit which adds
up and shows up as spending most time in wait4().

Bart

> > > -----Original Message-----
> > > From: Kent Gibson <warthog618@xxxxxxxxx>
> > > Sent: Monday, June 5, 2023 8:43 PM
> > > To: Slater, Joseph <joe.slater@xxxxxxxxxxxxx>
> > > Cc: linux-gpio@xxxxxxxxxxxxxxx; MacLeod, Randy
> > > <Randy.MacLeod@xxxxxxxxxxxxx>
> > > Subject: Re: [v3][libgpiod][PATCH 1/1] gpio-tools-test.bats: modify delays in
> > > toggle test
> > >
> > > On Mon, Jun 05, 2023 at 01:43:35PM -0700, joe.slater@xxxxxxxxxxxxx wrote:
> > > > From: Joe Slater <joe.slater@xxxxxxxxxxxxx>
> > > >
> > > > The test "gpioset: toggle (continuous)" uses fixed delays to test
> > > > toggling values.  This is not reliable, so we switch to looking for
> > > > transitions from one value to another.
> > > >
> > > > We wait for a transition up to 1.5 seconds.
> > > >
> > >
> > > For future reference, the subject line should've been "[libgpiod][PATCH v3]".
> > > The version goes within the [PATCH], and 1/1 is optional unless you have a cover
> > > letter.
> > >
> > > > Signed-off-by: Joe Slater <joe.slater@xxxxxxxxxxxxx>
> > > > ---
> > >
> > > Here you would normally list the changes between revisions.
> > > So I'm not sure what has actually changed since v1.
> > > The loop limit went from 10 to 15?
> > >
> > > >  tools/gpio-tools-test.bats | 24 +++++++++++++++++++-----
> > > >  1 file changed, 19 insertions(+), 5 deletions(-)
> > > >
> > > > diff --git a/tools/gpio-tools-test.bats b/tools/gpio-tools-test.bats
> > > > index c83ca7d..05d7138 100755
> > > > --- a/tools/gpio-tools-test.bats
> > > > +++ b/tools/gpio-tools-test.bats
> > > > @@ -141,6 +141,20 @@ gpiosim_check_value() {
> > > >     [ "$VAL" = "$EXPECTED" ]
> > > >  }
> > > >
> > > > +gpiosim_wait_value() {
> > > > +   local OFFSET=$2
> > > > +   local EXPECTED=$3
> > > > +   local DEVNAME=${GPIOSIM_DEV_NAME[$1]}
> > > > +   local CHIPNAME=${GPIOSIM_CHIP_NAME[$1]}
> > > > +   local
> > > PORT=$GPIOSIM_SYSFS/$DEVNAME/$CHIPNAME/sim_gpio$OFFSET/value
> > > > +
> > > > +   for i in {1..15}; do
> > > > +           [ "$(<$PORT)" = "$EXPECTED" ] && return
> > > > +           sleep 0.1
> > > > +   done
> > > > +   return 1
> > > > +}
> > > > +
> > > >  gpiosim_cleanup() {
> > > >     for CHIP in ${!GPIOSIM_CHIP_NAME[@]}
> > > >     do
> > > > @@ -1567,15 +1581,15 @@ request_release_line() {
> > > >     gpiosim_check_value sim0 4 0
> > > >     gpiosim_check_value sim0 7 0
> > > >
> > > > -   sleep 1
> > > > -
> > > > -   gpiosim_check_value sim0 1 0
> > > > +   # sleeping fixed amounts can be unreliable, so we
> > > > +   # sync to the toggles
> > > > +   #
> > >
> > > You said you would get rid of this comment.
> > >
> > >
> > > The patch works for me, so I'm otherwise fine with it.
> > >
> > > Cheers,
> > > Kent.