Skip to content

Commit

Permalink
Attempt to fix tests on CI.
Browse files Browse the repository at this point in the history
  • Loading branch information
renatoathaydes committed Feb 15, 2022
1 parent 2dd6292 commit 2c687cb
Show file tree
Hide file tree
Showing 2 changed files with 92 additions and 36 deletions.
116 changes: 80 additions & 36 deletions src/test/groovy/com/athaydes/logfx/concurrency/TaskRunnerSpec.groovy
Original file line number Diff line number Diff line change
@@ -1,5 +1,8 @@
package com.athaydes.logfx.concurrency


import groovy.transform.CompileStatic
import groovy.transform.TupleConstructor
import spock.lang.AutoCleanup
import spock.lang.Shared
import spock.lang.Specification
Expand All @@ -8,6 +11,11 @@ import spock.lang.Subject
import java.time.Duration
import java.util.concurrent.CountDownLatch
import java.util.concurrent.TimeUnit
import java.util.concurrent.atomic.AtomicInteger

import static com.google.code.tempusfugit.temporal.Duration.millis
import static com.google.code.tempusfugit.temporal.Timeout.timeout
import static com.google.code.tempusfugit.temporal.WaitFor.waitOrTimeout

class TaskRunnerSpec extends Specification {

Expand Down Expand Up @@ -38,53 +46,89 @@ class TaskRunnerSpec extends Specification {
start <= self && self <= end
}
when: 'A task is requested to run 10 times within 100 ms, but with max frequency once every 40ms'
def taskSchedulingCallCount = 10
List<Long> taskExecutionTimes = [ ].asSynchronized()
def latch = new CountDownLatch( taskSchedulingCallCount )
def startTime = System.currentTimeMillis()
def task = { taskExecutionTimes << ( System.currentTimeMillis() - startTime ) }
def maxFrequencyInMs = 40
10.times {
taskRunner.runWithMaxFrequency( task, maxFrequencyInMs, 0 )
latch.countDown()
sleep 10
int maxFrequencyInMs = 40
int minTaskRunsToWaitFor = 3
long startTime = System.currentTimeMillis()

// TIME: 0 10 20 30 40 50 60 70 80 90 100 110 120
// Schedule: X X X X X X X X X X X
// Run: T T... T... T...
// Slow Run: T... T... T...
RunnableTask task =
RunnableTask.runWith( taskRunner, 10, maxFrequencyInMs, 10, minTaskRunsToWaitFor, 200L )

final List<Long> taskExecutionTimes = task.taskExecutionTimes.toList()
.take( minTaskRunsToWaitFor )
.collect { it - startTime }

then: 'The task is run first nearly immediately after the first request'
def initialTime = taskExecutionTimes.first()
initialTime.between( 0L, maxFrequencyInMs - 1L )

and: 'The next execution times occur within the max frequency expected'
def time = initialTime
for ( long executionTime in taskExecutionTimes.tail() ) {
assert taskExecutionTimes &&
( executionTime - time ).between( maxFrequencyInMs, maxFrequencyInMs * 3 )
time = executionTime
}

then: 'All requests are performed within a timeout of 150ms'
latch.await( 150, TimeUnit.MILLISECONDS )
when: 'We request the task to run again'
sleep 60 // to avoid a delayed execution from the scheduled runs
startTime = System.currentTimeMillis()
def taskRuns = task.runCount.get()
taskRunner.runWithMaxFrequency( task, maxFrequencyInMs, 0 )

then: 'The task runs again almost immediately (within less than the maxPeriod)'
waitOrTimeout( { task.runCount.get() == taskRuns + 1 },
timeout( millis( maxFrequencyInMs - 1 ) ) )

}

}

and: 'The task is run first nearly immediately after the first request'
!taskExecutionTimes.isEmpty() && taskExecutionTimes.first().between( 0L, 30L )
@TupleConstructor
@CompileStatic
class RunnableTask implements Runnable {
AtomicInteger runCount
CountDownLatch latch
long[] taskExecutionTimes

@Override
void run() {
taskExecutionTimes[ runCount.getAndIncrement() ] = System.currentTimeMillis()
latch.countDown()
}

and: 'The second and third executions occur within 30ms of the expected times'
taskExecutionTimes.size() >= 3
@CompileStatic
static RunnableTask runWith( TaskRunner taskRunner,
int taskSchedulingCallCount,
int maxFrequencyInMs,
long schedulePeriod,
int minTaskRunsToWaitFor,
long maxTimeToWaitForInMs ) {
assert minTaskRunsToWaitFor < taskSchedulingCallCount

def delta2 = taskExecutionTimes[ 1 ] - taskExecutionTimes[ 0 ]
def delta3 = taskExecutionTimes[ 2 ] - taskExecutionTimes[ 1 ]
def task = new RunnableTask(
runCount: new AtomicInteger( 0 ),
latch: new CountDownLatch( minTaskRunsToWaitFor ),
taskExecutionTimes: new long[taskSchedulingCallCount] )

delta2.between( 40L, 70L ) && delta3.between( 40L, 70L )
taskSchedulingCallCount.times {
def scheduleTime = System.currentTimeMillis()

and: 'After another 50 ms max, one more executions occur'
for ( i in 1..5 ) {
if ( taskExecutionTimes.size() == 4 ) {
break
}
sleep 10 // wait a little and try again
}
taskRunner.runWithMaxFrequency( task, maxFrequencyInMs, 0 )

taskExecutionTimes.size() == 4
// it should not take any time to schedule tasks
assert System.currentTimeMillis() - scheduleTime < 100L

and: 'We wait 50 ms, no more executions occur'
sleep 50
taskExecutionTimes.size() == 4
sleep schedulePeriod
}

when: 'We request the task to run again'
startTime = System.currentTimeMillis()
taskRunner.runWithMaxFrequency( task, maxFrequencyInMs, 0 )
// this wait guarantees we get at least 'minTaskRunsToWaitFor' executions
assert task.latch.await( maxTimeToWaitForInMs, TimeUnit.MILLISECONDS )

then: 'The task runs again almost immediately (within 20 ms)'
sleep 20
taskExecutionTimes.size() == 5
return task
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ package com.athaydes.logfx.file

import com.athaydes.logfx.concurrency.TaskRunner
import groovy.transform.CompileStatic
import org.junit.jupiter.api.condition.OS
import spock.lang.AutoCleanup
import spock.lang.Shared
import spock.lang.Specification
Expand Down Expand Up @@ -49,6 +50,10 @@ class FileChangeWatcherSpec extends Specification {
Duration timeToWaitForNoFurtherEvents,
String description ) {
assertEventWithin timeout, description
if ( OS.WINDOWS.currentOs ) {
// allow double events on Windows
skipEventsWithin( Duration.ofMillis( 500 ) )
}
assertNoEventsFor timeToWaitForNoFurtherEvents, description
}

Expand All @@ -59,6 +64,13 @@ class FileChangeWatcherSpec extends Specification {
eventQueue.poll( timeout2.toMillis(), TimeUnit.MILLISECONDS )
}

private void skipEventsWithin( Duration timeout ) {
def max = System.currentTimeMillis() + timeout.toMillis()
while ( System.currentTimeMillis() < max ) {
eventQueue.poll( 10, TimeUnit.MILLISECONDS )
}
}

private void assertEventWithin( Duration timeout, String description ) {
assert eventQueue.poll( timeout.toMillis(), TimeUnit.MILLISECONDS ):
"Event '$description' did not occur within timeout"
Expand Down

0 comments on commit 2c687cb

Please sign in to comment.