Add the scheduling module

Three replicas of one application against one PostgreSQL database, proving
duplicate @Scheduled execution and then removing it with ShedLock: 24
executions where 8 were due, then 7 for 7 ticks.

Also measured: @SchedulerLock without @EnableSchedulerLock does nothing and
warns about nothing; spring.task.scheduling.pool.size=1 does not starve a
fixedRate job but delays it and fires 35 of 40 executions in a burst; and a
node whose clock is 40 seconds fast takes a live lock unless the provider
uses usingDbTime().
This commit is contained in:
2026-09-01 23:28:06 +05:30
parent 243cccd4ca
commit 6af6e4a3f1
31 changed files with 1373 additions and 1 deletions

View File

@@ -1,6 +1,7 @@
# spring-async-demo
Companion code for the asynchronous execution series on [ankurm.com](https://ankurm.com). Each
Companion code for the asynchronous execution and scheduling series on
[ankurm.com](https://ankurm.com). Each
directory is a self-contained Maven project for one article, with its own `pom.xml`, its own
numbered documentation chapters, and its own captured output under `docs/output/` — regenerated
by that module's `scripts/run-all.sh`, never typed by hand.
@@ -8,6 +9,7 @@ by that module's `scripts/run-all.sh`, never typed by hand.
| Module | Article | What it demonstrates |
|---|---|---|
| [`async/`](async/README.md) | [@Async in Spring Boot 4: Executors, Virtual Threads and the Self-Invocation Trap](https://ankurm.com/spring-boot-4-async-executors-virtual-threads/) | Which thread a method actually ran on, in every case where the answer is not the one you expect |
| [`scheduling/`](scheduling/README.md) | [@Scheduled, ShedLock and Distributed Cron: Scheduling That Survives Three Replicas](https://ankurm.com/spring-scheduled-shedlock-distributed-cron/) | Three replicas against one database running the same job three times, then one row and one conditional UPDATE fixing it |
## Common ground
@@ -20,6 +22,15 @@ one: the name of the thread that ran the work, returned by the code itself. Timi
fast synchronous call from an asynchronous one, which is why `@Async` failures survive so long in
production.
The two modules share a mechanism, which is why they live together: both `@Async` and ShedLock's
default `PROXY_METHOD` intercept mode are Spring AOP proxies. Every proxy limitation the `async`
module measures — self-invocation, `final` methods — applies unchanged to a
`@SchedulerLock` method, and silently produces an unlocked job rather than a synchronous one.
The `scheduling` module also needs a database. `scheduling/scripts/postgres.sh` unpacks a
throwaway PostgreSQL 14 into `target/` with no Docker and no root, which is how its transcripts
were produced; `docker-compose.yml` is there for anyone who would rather use Docker.
## Licence
MIT — see [LICENSE](LICENSE).

15
scheduling/Dockerfile Normal file
View File

@@ -0,0 +1,15 @@
# Used only by docker-compose.yml. The committed transcripts under docs/output/ were produced
# without Docker, by scripts/three-replicas.sh against the PostgreSQL that scripts/postgres.sh
# unpacks into target/.
FROM eclipse-temurin:25-jdk AS build
WORKDIR /src
COPY pom.xml .
RUN --mount=type=cache,target=/root/.m2 \
apt-get update && apt-get install -y --no-install-recommends maven && \
mvn -B -q dependency:go-offline
COPY src ./src
RUN --mount=type=cache,target=/root/.m2 mvn -B -q -DskipTests package
FROM eclipse-temurin:25-jre
COPY --from=build /src/target/scheduling-1.0.jar /app.jar
ENTRYPOINT ["java", "-jar", "/app.jar"]

70
scheduling/README.md Normal file
View File

@@ -0,0 +1,70 @@
# scheduling
Companion project for **@Scheduled, ShedLock and Distributed Cron: Scheduling That Survives Three
Replicas** on [ankurm.com](https://ankurm.com).
Three replicas of one Spring Boot application run against one PostgreSQL database, and the
`job_execution` table records who ran what and when. Counting rows is the measurement.
## Verified stack
| Component | Version | Source of the number |
|---|---|---|
| JDK | 25.0.4.1+1 (Temurin) | `java -version` |
| Spring Boot | 4.1.1 | `maven-metadata.xml` on Maven Central |
| Spring Framework | 7.0.9 | `spring-boot-dependencies-4.1.1.pom` |
| ShedLock | 7.9.0 | `maven-metadata.xml`; **not managed by Boot**, so it is pinned in `pom.xml` |
| PostgreSQL | 14.24 | the broker the transcripts ran against; `docker-compose.yml` uses 17 |
## Quickstart
```bash
scripts/postgres.sh start # throwaway PostgreSQL 14 on :55432, no Docker, no root
scripts/three-replicas.sh unlocked # 24 executions where 8 were due
scripts/three-replicas.sh locked # 7 executions for 7 ticks
mvn test # scheduler-pool and clock-skew evidence
scripts/run-all.sh # regenerates every docs/output/ file
```
With Docker instead:
```bash
docker compose up --build # unlocked
PROFILE=locked docker compose up --build # locked
```
## Profiles
| Profile | What is active | Result |
|---|---|---|
| `unlocked` | `@SchedulerLock` on the job, and nothing else | every replica runs every tick |
| `locked` | `LockConfiguration`: `@EnableSchedulerLock` + a `LockProvider` with `usingDbTime()` | one execution per tick |
| `appclock` | the same, with a `LockProvider` that has no `usingDbTime()` | used by the clock-skew experiment |
| `poolprobe` | three competing `@Scheduled` methods | used by the scheduler-pool tests |
## Documentation
| Chapter | What it settles |
|---|---|
| [01 Three replicas, three executions](docs/01-three-replicas-three-executions.md) | The failure, and why `@SchedulerLock` alone does nothing |
| [02 The lock](docs/02-the-lock.md) | How one row and one conditional `UPDATE` fix it, and what the two durations mean |
| [03 One scheduler thread](docs/03-one-scheduler-thread.md) | `pool.size=1`: the same execution count, arriving in a burst |
| [04 Clock skew](docs/04-clock-skew.md) | A 40-second-fast node taking a live lock, and `usingDbTime()` refusing it |
| [05 When not to use a lock](docs/05-when-not-to-use-a-lock.md) | Idempotence, Kubernetes `CronJob`, Quartz, and a pre-ship checklist |
## Captured output
| File | What it shows |
|---|---|
| [`three-replicas-unlocked.txt`](docs/output/three-replicas-unlocked.txt) | 8 + 8 + 8 executions, 9 overlapping pairs, an empty lock table |
| [`three-replicas-locked.txt`](docs/output/three-replicas-locked.txt) | 7 executions, 0 overlaps, one lock row |
| [`scheduler-pool-1.txt`](docs/output/scheduler-pool-1.txt) | 40 executions, longest gap 1995 ms, 35 of them in a burst |
| [`scheduler-pool-4.txt`](docs/output/scheduler-pool-4.txt) | 41 executions, longest gap 201 ms, no burst |
| [`clock-skew.txt`](docs/output/clock-skew.txt) | Two holders of one lock, and `usingDbTime()` preventing it |
| [`tests.txt`](docs/output/tests.txt) | The test run behind the last three |
## A note on the database
`scripts/postgres.sh` downloads the PostgreSQL 14 `.deb` packages and unpacks them into
`target/pg` — no Docker, no root, no system-wide install. It exists because the transcripts had to
be reproducible on a machine with neither. If you have Docker, `docker-compose.yml` is simpler.

View File

@@ -0,0 +1,51 @@
# Three replicas and one database, which is the smallest deployment in which a @Scheduled method
# misbehaves. Run `docker compose up --scale app=3` if you would rather set the replica count
# from the command line; the three named services below exist so that each one gets a stable
# INSTANCE_ID in the transcript.
#
# docker compose up --build
# docker compose exec db psql -U app -d shedlockdemo -c \
# "select instance_id, count(*) from job_execution group by instance_id"
#
# SPRING_PROFILES_ACTIVE=unlocked reproduces the duplicate executions; switch it to `locked` to
# watch the count collapse to one per tick.
services:
db:
image: postgres:17
environment:
POSTGRES_USER: app
POSTGRES_DB: shedlockdemo
POSTGRES_HOST_AUTH_METHOD: trust
ports: ["5432:5432"]
healthcheck:
test: ["CMD-SHELL", "pg_isready -U app -d shedlockdemo"]
interval: 2s
timeout: 3s
retries: 20
replica-1: &replica
build: .
depends_on:
db: { condition: service_healthy }
environment:
DB_URL: jdbc:postgresql://db:5432/shedlockdemo
DB_USER: app
INSTANCE_ID: replica-1
SPRING_PROFILES_ACTIVE: ${PROFILE:-unlocked}
replica-2:
<<: *replica
environment:
DB_URL: jdbc:postgresql://db:5432/shedlockdemo
DB_USER: app
INSTANCE_ID: replica-2
SPRING_PROFILES_ACTIVE: ${PROFILE:-unlocked}
replica-3:
<<: *replica
environment:
DB_URL: jdbc:postgresql://db:5432/shedlockdemo
DB_USER: app
INSTANCE_ID: replica-3
SPRING_PROFILES_ACTIVE: ${PROFILE:-unlocked}

View File

@@ -0,0 +1,75 @@
[README](../README.md) · next: [The lock](02-the-lock.md)
# 1. Three replicas, three executions
`@Scheduled` is a per-JVM timer. It has no idea that other JVMs exist. Scale a deployment to
three replicas and every `@Scheduled` method in the application runs three times per tick, on
three machines, at almost the same instant.
That is the whole problem, and it is worth seeing rather than reading. `scripts/three-replicas.sh`
starts three copies of this application against one PostgreSQL database, lets the 3-second
schedule tick for 30 seconds, and counts.
From [`docs/output/three-replicas-unlocked.txt`](output/three-replicas-unlocked.txt):
```
-- executions per replica --
instance_id | count
-------------+-------
replica-1 | 8
replica-2 | 8
replica-3 | 8
-- pairs of executions that overlapped --
overlapping_pairs
-------------------
8
first | first_at | second | second_at
-----------+--------------+-----------+--------------
replica-1 | 22:48:54.564 | replica-3 | 22:48:54.752
replica-1 | 22:48:57.551 | replica-3 | 22:48:57.736
replica-1 | 22:49:00.551 | replica-3 | 22:49:00.736
```
Twenty-four executions where eight were due, and eight of them started while another replica was
still inside the method — 188 milliseconds apart in the first pair, against a job that only takes
200 milliseconds. Anything in that method which
is not idempotent is now a support ticket: a second invoice email, a double refund, two rows
where the unique constraint you did not add would have saved you.
## The part that makes it hard to spot
`ReportJob` is annotated `@SchedulerLock` in this run. Look at the end of the same transcript:
```
-- the lock row --
name | locked_by | locked_at | lock_until
------+-----------+-----------+------------
(0 rows)
```
The annotation is present, the lock table exists, the application started cleanly, and nothing
was ever locked. `@SchedulerLock` on its own is inert: it needs `@EnableSchedulerLock` to install
the interceptor and a `LockProvider` bean to have somewhere to record the lock. In this module
both live on `LockConfiguration`, which is `@Profile("locked")`.
There is no warning for the missing half. That is the single most important sentence in this
module — an application with the annotation and without the plumbing behaves exactly like an
application with no locking at all, and it looks locked in code review.
## Reproducing it
```bash
scripts/postgres.sh start # a throwaway PostgreSQL 14, no Docker, no root
scripts/three-replicas.sh unlocked
scripts/three-replicas.sh locked
```
or, with Docker:
```bash
docker compose up --build # PROFILE=locked docker compose up --build
```
next: [The lock](02-the-lock.md)

View File

@@ -0,0 +1,90 @@
prev: [Three replicas, three executions](01-three-replicas-three-executions.md) · [README](../README.md) · next: [One scheduler thread](03-one-scheduler-thread.md)
# 2. The lock
Activate `LockConfiguration` and the same 30-second run produces this
([`docs/output/three-replicas-locked.txt`](output/three-replicas-locked.txt)):
```
-- executions per replica --
instance_id | count
-------------+-------
replica-2 | 1
replica-3 | 6
-- pairs of executions that overlapped --
overlapping_pairs
-------------------
0
-- the lock row --
name | locked_by | locked_at | lock_until
---------------+-----------+--------------+--------------
nightlyReport | unknown | 17:19:46.921 | 17:19:47.921
```
Seven executions for seven ticks, no overlap. The mechanism is one row in one table and a
conditional `UPDATE`: acquire means "set `lock_until` to a future time **where** `lock_until` is
already in the past", and only one replica's update can win because the row is locked for the
duration of that statement.
Three things in that transcript deserve attention.
## ShedLock does not distribute work
Six of the seven executions are `replica-3`. The lock is not a queue and there is no round-robin:
whichever replica's timer fires first each tick takes the lock, and on a stable cluster that is
overwhelmingly the same replica &mdash; here `replica-2` won the first tick and then never won
another. This is correct behaviour for "run exactly once" and
completely wrong if what you actually wanted was "spread the work across the cluster". For that
you want a work queue, not a lock.
## `locked_by` is not identity
It reads `unknown` above. ShedLock fills that column with the host name, and the host name of the
container that produced this transcript does not resolve, so it falls back. It is a diagnostic
field, never read back for correctness — but it does mean that on Kubernetes you often get a
column full of pod hashes or of `unknown`, and it is worth setting something meaningful if you
plan to use it during an incident.
## The timestamps are in a different time zone from your own
`locked_at` reads `17:19:46` while the execution recorded at the same moment in the same file
reads `22:49:46`. That is not a
bug; it is `usingDbTime()` doing its job. With it, the timestamps are written by PostgreSQL in
UTC, whereas `started_at` is written by the application in the JVM's zone. Anyone eyeballing the
`shedlock` table next to the application's own tables will see a five-and-a-half-hour discrepancy
and think the lock is stale. It is not.
## The two durations
```java
@SchedulerLock(name = "nightlyReport", lockAtMostFor = "PT20S", lockAtLeastFor = "PT1S")
```
**`lockAtMostFor`** is the answer to "the holder was `kill -9`'d; how long before somebody else
may run this?" It must be longer than the longest the job could possibly take, because when it
expires the lock is available whether or not the job finished. Set it to five minutes for a job
that normally takes ten seconds, and accept a five-minute gap after a crash — that is the trade,
and there is no setting that avoids it.
**`lockAtLeastFor`** keeps the lock held for a minimum period after a fast job finishes. It exists
for clock skew and for schedules where two replicas' timers fire within milliseconds of each
other: without it, a job that completes in 20 ms releases the lock in time for the next replica's
tick to pick it up, and you are back to two executions.
`@EnableSchedulerLock(defaultLockAtMostFor = ...)` has no default value in the annotation, so it
must be supplied. That is deliberate: there is no safe guess.
## `interceptMode`
ShedLock 7 defaults to `PROXY_METHOD`. The `PROXY_SCHEDULER` mode that most tutorials still show
is deprecated, and its own Javadoc says it "requires a reflection hack to work well with Spring
6.2". Leave the default alone.
Because `PROXY_METHOD` is a Spring AOP proxy, everything from
[the `@Async` article](https://ankurm.com/spring-boot-4-async-executors-virtual-threads/) applies
here too: a `@SchedulerLock` method called from inside its own class is not locked, and a `final`
method is not locked.
next: [One scheduler thread](03-one-scheduler-thread.md)

View File

@@ -0,0 +1,56 @@
prev: [The lock](02-the-lock.md) · [README](../README.md) · next: [Clock skew](04-clock-skew.md)
# 3. One scheduler thread
`spring.task.scheduling.pool.size` defaults to **1**. Every `@Scheduled` method in the
application shares that one thread.
The expected consequence is that a slow job starves the others. What actually happens is more
interesting, and considerably worse.
Three scheduled methods — one that sleeps 1800 ms on a 2000 ms schedule, one on a 200 ms
schedule, one that throws — running for eight seconds. First with the default single thread
([output](output/scheduler-pool-1.txt)), then with four
([output](output/scheduler-pool-4.txt)):
| | pool.size=1 | pool.size=4 |
|---|---|---|
| `fast()` executions | 40 | 41 |
| longest gap between two `fast()` executions | **1995 ms** | 201 ms |
| `fast()` executions starting within 20 ms of the previous one | **35** | 0 |
| distinct scheduler threads | 1 | 4 |
The execution *count* is the same. A `fixedRate` schedule does not skip a tick it could not run:
the missed executions accumulate and are then fired back to back the moment the thread is free.
Thirty-five of the forty executions arrived in a burst.
So the metric everyone has — "the job ran 40 times, as expected" — is green, while the job's
actual behaviour is two seconds of silence followed by thirty-five invocations in a few
milliseconds. If that job calls a rate-limited API, or opens a database connection each time, the
burst is the incident.
## What to set
- **`spring.task.scheduling.pool.size`**: at least the number of `@Scheduled` methods that can
overlap. It costs a handful of mostly idle threads.
- **`fixedDelay` instead of `fixedRate`** where "every N seconds" really means "N seconds after
the last one finished". `fixedDelay` schedules the next run only after the current one
completes, so it cannot accumulate a backlog to burst through.
- **`spring.threads.virtual.enabled=true`** replaces the pool with a `SimpleAsyncTaskScheduler`
over virtual threads, which removes the shared-thread problem entirely. It also removes the
bound: `spring.task.scheduling.pool.size` is one of the properties Boot's own metadata marks
as having no effect when virtual threads are on.
## An exception does not stop the schedule
`throwing()` threw on all 27 of its executions and kept its schedule. Spring wraps a scheduled
method in `TaskUtils.LOG_AND_SUPPRESS_ERROR_HANDLER`, so the exception is logged by
`o.s.s.s.TaskUtils$LoggingErrorHandler` as `Unexpected error occurred in scheduled task` and
discarded. A raw `ScheduledExecutorService` would have cancelled the task after the first
failure — which is where the folklore comes from, and it does not apply to `@Scheduled`.
The flip side is that a job which has been failing since the last deploy produces nothing but a
recurring `ERROR` line. Supply your own `SchedulingConfigurer` with an error handler if you want
a metric.
next: [Clock skew](04-clock-skew.md)

View File

@@ -0,0 +1,56 @@
prev: [One scheduler thread](03-one-scheduler-thread.md) · [README](../README.md) · next: [When not to use a lock](05-when-not-to-use-a-lock.md)
# 4. Clock skew, and what `usingDbTime()` is for
```java
JdbcTemplateLockProvider.Configuration.builder()
.withJdbcTemplate(new JdbcTemplate(dataSource))
.usingDbTime()
.build();
```
Without `usingDbTime()`, each replica writes `lock_until` from its own clock and compares
`lock_until` against its own clock. The lock is then only as good as the agreement between three
machines about what time it is.
Three replicas racing is not a proof, because a race can go either way. `ClockSkewTest` drives
the `LockProvider` directly instead, so the two acquisitions are ordered by the test and the only
variable is what the second caller believes the time to be
([`docs/output/clock-skew.txt`](output/clock-skew.txt)):
```
lockAtMostFor = 30s, both callers ask for the same lock name.
JdbcTemplateLockProvider WITHOUT usingDbTime()
node with a correct clock : acquired
node with a clock 40s fast : ACQUIRED -- two holders at the same time
JdbcTemplateLockProvider WITH usingDbTime()
node with a correct clock : acquired
node with a clock 40s fast : refused
```
A node whose clock is ahead by more than `lockAtMostFor` considers every live lock expired. It
takes the lock while somebody else is holding it, and the whole mechanism silently stops working
— for that node only, which is why it presents as "it usually runs once".
The skew is simulated with ShedLock's own `ClockProvider.setClock(...)`, which is what the
provider reads for "now" on the non-database path. That is also the cheapest way to test this on
your own code: no NTP fiddling and no root.
`usingDbTime()` moves both the write and the comparison into a SQL statement, so there is exactly
one clock in the system. It is supported on PostgreSQL, MySQL, MariaDB, MS SQL, Oracle, DB2, HSQL
and H2.
**Use it.** Forty seconds of skew is not exotic — a VM resuming from a snapshot, a container on a
host with a broken NTP client, or a laptop that just woke up will all do it, and cloud instances
drift more than people expect.
## What it does not fix
`usingDbTime()` makes expiry decisions consistent. It does not shorten the window created by a
crash: if a holder dies, the lock still stays held until `lockAtMostFor` elapses. Nor does it help
if your `lockAtMostFor` is shorter than the job — in that case the lock expires legitimately, a
second replica starts, and both run. Size `lockAtMostFor` against the worst case, not the average.
next: [When not to use a lock](05-when-not-to-use-a-lock.md)

View File

@@ -0,0 +1,46 @@
prev: [Clock skew](04-clock-skew.md) · [README](../README.md)
# 5. When not to use a lock
ShedLock is small, it has one dependency on your database, and it solves the stated problem. It
is still worth asking whether the problem should exist.
**Make the job idempotent instead.** A lock is a way of avoiding a second execution. Idempotence
is a way of not caring about one. If the job's work can be keyed — "mark invoices dated
2026-09-01 as sent, where they are not already marked" — then three replicas running it produce
one outcome and you have removed a distributed-systems dependency rather than adding one. This is
almost always the better engineering, and it is almost never what the article you searched for
suggests.
**A lock is not a guarantee of exactly-once.** It is a guarantee of at-most-one-per-lock-window,
which is different. If the holder dies halfway, the job did not complete and nothing retries it —
ShedLock has no notion of failure, only of expiry. Pairing it with a job table that records
completion is what makes "exactly once" true, and at that point the job table is doing most of
the work.
**Consider the scheduler you already have.** A Kubernetes `CronJob` runs one pod per schedule and
needs no lock, no library and no table; it costs you a pod start per run and the schedule lives
outside the application. Quartz in clustered mode owns misfire policy, persistence and recovery,
at the price of eleven tables and a great deal of configuration. ShedLock sits between them: it
adds a lock to the scheduler you already have, and deliberately adds nothing else.
**A lock provider needs its store to be consistent.** The JDBC provider is safe because a
conditional `UPDATE` on one row is atomic in every relational database. The Redis provider is
safe on a single instance and, as its own documentation notes, is subject to the well-known
argument about locks over Redis replication. If your store is eventually consistent, your lock
is too.
## A short checklist for the version you ship
- `@EnableSchedulerLock` present, and a `LockProvider` bean present — without both, the
annotation does nothing ([chapter 1](01-three-replicas-three-executions.md))
- `usingDbTime()` on ([chapter 4](04-clock-skew.md))
- `lockAtMostFor` longer than the worst-case run time, and you have accepted the gap it implies
after a crash
- `lockAtLeastFor` non-zero for any job shorter than the interval between two replicas' timers
- `spring.task.scheduling.pool.size` raised above 1 ([chapter 3](03-one-scheduler-thread.md))
- the lock names are unique per job — two jobs sharing a name share a lock, and one of them stops
running
- the method carrying `@SchedulerLock` is called from outside its own class, and is not `final`
[README](../README.md)

View File

@@ -0,0 +1,17 @@
== One lock, two holders: what usingDbTime() prevents ==
lockAtMostFor = 30s, both callers ask for the same lock name.
JdbcTemplateLockProvider WITHOUT usingDbTime()
node with a correct clock : acquired
node with a clock 40s fast : ACQUIRED -- two holders at the same time
JdbcTemplateLockProvider WITH usingDbTime()
node with a correct clock : acquired
node with a clock 40s fast : refused
Without usingDbTime() the expiry comparison happens against the calling
JVM's clock, so a node that is ahead by more than lockAtMostFor considers
every live lock expired. With it, both the write and the comparison happen
in the database, and there is only one clock in the system.

View File

@@ -0,0 +1,12 @@
== spring.task.scheduling.pool.size=1 (the default) ==
over 8 seconds, three @Scheduled methods on one application
slow() fixedRate 2000 ms, sleeps 1800 ms : 5 executions
fast() fixedRate 200 ms : 40 executions
throwing() fixedRate 300 ms, always throws : 27 executions
distinct scheduler threads : 1 [scheduling-1]
longest gap between two fast() executions : 1995 ms (200 ms was the schedule)
fast() executions that started within 20 ms
of the previous one (the catch-up burst) : 35

View File

@@ -0,0 +1,18 @@
== spring.task.scheduling.pool.size=4 ==
over 8 seconds, three @Scheduled methods on one application
slow() fixedRate 2000 ms, sleeps 1800 ms : 5 executions
fast() fixedRate 200 ms : 41 executions
throwing() fixedRate 300 ms, always throws : 27 executions
distinct scheduler threads : 4 [scheduling-1, scheduling-2, scheduling-3, scheduling-4]
longest gap between two fast() executions : 200 ms (200 ms was the schedule)
fast() executions that started within 20 ms
of the previous one (the catch-up burst) : 0
throwing() kept its schedule after every failure. Spring wraps a scheduled
method in TaskUtils.LOG_AND_SUPPRESS_ERROR_HANDLER, so each exception is
logged by o.s.s.s.TaskUtils$LoggingErrorHandler as "Unexpected error
occurred in scheduled task" and then discarded. A raw
ScheduledExecutorService would have cancelled the task at the first one.

View File

@@ -0,0 +1,8 @@
[INFO] Running com.ankurm.scheduling.SingleSchedulerThreadTest
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 10.10 s -- in com.ankurm.scheduling.SingleSchedulerThreadTest
[INFO] Running com.ankurm.scheduling.LargerSchedulerPoolTest
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 9.422 s -- in com.ankurm.scheduling.LargerSchedulerPoolTest
[INFO] Running com.ankurm.scheduling.ClockSkewTest
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.964 s -- in com.ankurm.scheduling.ClockSkewTest
[INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0
[INFO] BUILD SUCCESS

View File

@@ -0,0 +1,37 @@
profile=locked replicas=3 run-for=30s job rate=3s job duration=PT0.2S replica-3 clock skew=0s
-- every execution, in order --
instance_id | started_at
-------------+--------------
replica-2 | 22:49:29.233
replica-3 | 22:49:31.931
replica-3 | 22:49:34.925
replica-3 | 22:49:37.934
replica-3 | 22:49:40.934
replica-3 | 22:49:43.925
replica-3 | 22:49:46.934
(7 rows)
-- executions per replica --
instance_id | count
-------------+-------
replica-2 | 1
replica-3 | 6
(2 rows)
-- pairs of executions that overlapped (a second replica started while the first was still working) --
overlapping_pairs
-------------------
0
(1 row)
first | first_at | second | second_at
-------+----------+--------+-----------
(0 rows)
-- the lock row --
name | locked_by | locked_at | lock_until
---------------+-----------+--------------+--------------
nightlyReport | unknown | 17:19:46.921 | 17:19:47.921
(1 row)

View File

@@ -0,0 +1,60 @@
profile=unlocked replicas=3 run-for=30s job rate=3s job duration=PT0.2S replica-3 clock skew=0s
-- every execution, in order --
instance_id | started_at
-------------+--------------
replica-1 | 22:48:54.564
replica-3 | 22:48:54.752
replica-2 | 22:48:55.052
replica-1 | 22:48:57.551
replica-3 | 22:48:57.736
replica-2 | 22:48:58.030
replica-1 | 22:49:00.551
replica-3 | 22:49:00.736
replica-2 | 22:49:01.030
replica-1 | 22:49:03.551
replica-3 | 22:49:03.736
replica-2 | 22:49:04.030
replica-1 | 22:49:06.551
replica-3 | 22:49:06.736
replica-2 | 22:49:07.030
replica-1 | 22:49:09.551
replica-3 | 22:49:09.736
replica-2 | 22:49:10.030
replica-1 | 22:49:12.551
replica-3 | 22:49:12.736
replica-2 | 22:49:13.030
replica-1 | 22:49:15.551
replica-3 | 22:49:15.736
replica-2 | 22:49:16.030
(24 rows)
-- executions per replica --
instance_id | count
-------------+-------
replica-1 | 8
replica-2 | 8
replica-3 | 8
(3 rows)
-- pairs of executions that overlapped (a second replica started while the first was still working) --
overlapping_pairs
-------------------
8
(1 row)
first | first_at | second | second_at
-----------+--------------+-----------+--------------
replica-1 | 22:48:54.564 | replica-3 | 22:48:54.752
replica-1 | 22:48:57.551 | replica-3 | 22:48:57.736
replica-1 | 22:49:00.551 | replica-3 | 22:49:00.736
replica-1 | 22:49:03.551 | replica-3 | 22:49:03.736
replica-1 | 22:49:06.551 | replica-3 | 22:49:06.736
replica-1 | 22:49:09.551 | replica-3 | 22:49:09.736
(6 rows)
-- the lock row --
name | locked_by | locked_at | lock_until
------+-----------+-----------+------------
(0 rows)

68
scheduling/pom.xml Normal file
View File

@@ -0,0 +1,68 @@
<project xmlns="http://maven.apache.org/POM/4.0.0">
<modelVersion>4.0.0</modelVersion>
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>4.1.1</version>
<relativePath/>
</parent>
<groupId>com.ankurm</groupId>
<artifactId>scheduling</artifactId>
<version>1.0</version>
<packaging>jar</packaging>
<properties>
<java.version>25</java.version>
<project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
<!-- ShedLock is NOT managed by spring-boot-dependencies, so this version is pinned here.
7.9.0 was read from maven-metadata.xml on Maven Central; its jars are compiled for
Java 17 (MANIFEST Java-Version: 17, class file major version 61). -->
<shedlock.version>7.9.0</shedlock.version>
</properties>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter</artifactId>
</dependency>
<!-- spring-boot-starter-jdbc, not a bare spring-jdbc dependency: in Boot 4 the DataSource
and JdbcTemplate auto-configuration lives in the spring-boot-jdbc module, which the
starter brings and spring-jdbc does not. -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-jdbc</artifactId>
</dependency>
<dependency>
<groupId>org.postgresql</groupId>
<artifactId>postgresql</artifactId>
</dependency>
<dependency>
<groupId>net.javacrumbs.shedlock</groupId>
<artifactId>shedlock-spring</artifactId>
<version>${shedlock.version}</version>
</dependency>
<dependency>
<groupId>net.javacrumbs.shedlock</groupId>
<artifactId>shedlock-provider-jdbc-template</artifactId>
<version>${shedlock.version}</version>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<scope>test</scope>
</dependency>
</dependencies>
<build>
<plugins>
<plugin>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-maven-plugin</artifactId>
</plugin>
</plugins>
</build>
</project>

47
scheduling/scripts/postgres.sh Executable file
View File

@@ -0,0 +1,47 @@
#!/usr/bin/env bash
# Starts a throwaway PostgreSQL 14 on port 55432 with no Docker and no root.
#
# On a Debian/Ubuntu machine the .deb packages can simply be downloaded and unpacked into a
# prefix; PostgreSQL does not need to be installed system-wide and refuses to run as root anyway.
# This is how docs/output/ was produced. If you have Docker, docker-compose.yml is easier.
#
# scripts/postgres.sh start|stop|psql
set -euo pipefail
cd "$(dirname "$0")/.."
PREFIX="$PWD/target/pg"
PGROOT="$PREFIX/root"
PGDATA="$PREFIX/data"
export PATH="$PGROOT/usr/lib/postgresql/14/bin:$PATH"
export LD_LIBRARY_PATH="$PGROOT/usr/lib/x86_64-linux-gnu:$PGROOT/lib/x86_64-linux-gnu:${LD_LIBRARY_PATH:-}"
install_pg() {
mkdir -p "$PREFIX/debs" "$PGROOT"
( cd "$PREFIX/debs"
for p in postgresql-14 postgresql-client-14 postgresql-common postgresql-client-common \
libpq5 libllvm14 libicu70 libssl3 libxslt1.1 libxml2 libedit2 libbsd0 libmd0 \
zlib1g liblz4-1 libzstd1 libtinfo6 libncurses6 libcom-err2 libkrb5-3 libk5crypto3 \
libkrb5support0 libgssapi-krb5-2 libkeyutils1 libsasl2-2 libldap-2.5-0 libgnutls30 \
libnettle8 libhogweed6 libgmp10 libp11-kit0 libtasn1-6 libidn2-0 libunistring2 libffi8; do
apt-get download "$p" >/dev/null 2>&1 || true
done
for d in *.deb; do dpkg -x "$d" "$PGROOT" 2>/dev/null || true; done )
}
case "${1:-start}" in
start)
[ -x "$PGROOT/usr/lib/postgresql/14/bin/initdb" ] || install_pg
if [ ! -d "$PGDATA" ]; then
initdb -D "$PGDATA" -U app --auth=trust -E UTF8 >/dev/null
fi
pg_ctl -D "$PGDATA" -o "-p 55432 -k $PREFIX -c listen_addresses=127.0.0.1" \
-l "$PREFIX/pg.log" start >/dev/null 2>&1 || true
for _ in $(seq 1 30); do pg_isready -h 127.0.0.1 -p 55432 >/dev/null 2>&1 && break; sleep 1; done
psql -h 127.0.0.1 -p 55432 -U app -d postgres -tc \
"select 1 from pg_database where datname='shedlockdemo'" | grep -q 1 || \
psql -h 127.0.0.1 -p 55432 -U app -d postgres -q -c "create database shedlockdemo"
pg_isready -h 127.0.0.1 -p 55432
;;
stop) pg_ctl -D "$PGDATA" stop -m fast >/dev/null 2>&1 || true ;;
psql) shift; psql -h 127.0.0.1 -p 55432 -U app -d shedlockdemo "$@" ;;
*) echo "usage: $0 start|stop|psql" >&2; exit 2 ;;
esac

16
scheduling/scripts/run-all.sh Executable file
View File

@@ -0,0 +1,16 @@
#!/usr/bin/env bash
# Regenerates every file under docs/output/. Takes about three minutes: two three-replica runs of
# 30 seconds each plus the test suite, and three JVMs need roughly ten seconds to start on a
# small box.
set -euo pipefail
cd "$(dirname "$0")/.."
mkdir -p docs/output
scripts/postgres.sh start >/dev/null
mvn -B -q -DskipTests package
mvn -B test 2>&1 | grep -E 'Running |Tests run:|BUILD ' > docs/output/tests.txt
scripts/three-replicas.sh unlocked > docs/output/three-replicas-unlocked.txt
scripts/three-replicas.sh locked > docs/output/three-replicas-locked.txt
echo "regenerated:"; ls -1 docs/output

View File

@@ -0,0 +1,52 @@
#!/usr/bin/env bash
# Starts three replicas of the application against one database, lets the schedule tick, and
# tallies who ran the job.
#
# scripts/three-replicas.sh unlocked # no @EnableSchedulerLock: every replica runs it
# scripts/three-replicas.sh locked # ShedLock with usingDbTime()
# scripts/three-replicas.sh appclock 40 # ShedLock without usingDbTime(), replica-3 40s fast
#
# Environment:
# RUN_FOR seconds to let the schedule tick (default 30; three JVMs need ~10s to start)
# JOB_DURATION ISO-8601 duration the job sleeps for (default PT0.2S)
set -euo pipefail
cd "$(dirname "$0")/.."
PROFILE="${1:-unlocked}"
SKEW_SECONDS="${2:-0}"
RUN_FOR="${RUN_FOR:-30}"
JOB_DURATION="${JOB_DURATION:-PT0.2S}"
JAR=target/scheduling-1.0.jar
PSQL=(scripts/postgres.sh psql)
[ -f "$JAR" ] || mvn -B -q -DskipTests package
"${PSQL[@]}" -q -c "delete from job_execution" -c "delete from shedlock" >/dev/null 2>&1 || true
pids=()
for n in 1 2 3; do
skew=()
if [ "$SKEW_SECONDS" != "0" ] && [ "$n" = "3" ]; then
skew=(-Dclock.skew="PT${SKEW_SECONDS}S")
fi
java -Dspring.profiles.active="$PROFILE" -DINSTANCE_ID="replica-$n" \
-Djob.duration="$JOB_DURATION" "${skew[@]}" \
-jar "$JAR" > "target/replica-$n.log" 2>&1 &
pids+=($!)
done
sleep "$RUN_FOR"
for p in "${pids[@]}"; do kill "$p" 2>/dev/null || true; done
wait 2>/dev/null || true
echo "profile=$PROFILE replicas=3 run-for=${RUN_FOR}s job rate=3s job duration=$JOB_DURATION replica-3 clock skew=${SKEW_SECONDS}s"
echo
echo "-- every execution, in order --"
"${PSQL[@]}" -c "select instance_id, to_char(started_at,'HH24:MI:SS.MS') as started_at from job_execution order by started_at"
echo "-- executions per replica --"
"${PSQL[@]}" -c "select instance_id, count(*) from job_execution group by instance_id order by instance_id"
OVERLAP="b.id > a.id and b.instance_id <> a.instance_id and b.started_at < a.started_at + interval '$JOB_DURATION'"
echo "-- pairs of executions that overlapped (a second replica started while the first was still working) --"
"${PSQL[@]}" -c "select count(*) as overlapping_pairs from job_execution a join job_execution b on $OVERLAP"
"${PSQL[@]}" -c "select a.instance_id as first, to_char(a.started_at, 'HH24:MI:SS.MS') as first_at, b.instance_id as second, to_char(b.started_at, 'HH24:MI:SS.MS') as second_at from job_execution a join job_execution b on $OVERLAP order by a.started_at limit 6"
echo "-- the lock row --"
"${PSQL[@]}" -c "select name, locked_by, to_char(locked_at,'HH24:MI:SS.MS') as locked_at, to_char(lock_until,'HH24:MI:SS.MS') as lock_until from shedlock"

View File

@@ -0,0 +1,33 @@
package com.ankurm.scheduling;
import javax.sql.DataSource;
import net.javacrumbs.shedlock.core.LockProvider;
import net.javacrumbs.shedlock.provider.jdbctemplate.JdbcTemplateLockProvider;
import net.javacrumbs.shedlock.spring.annotation.EnableSchedulerLock;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.Profile;
import org.springframework.jdbc.core.JdbcTemplate;
/**
* The same lock provider without {@code usingDbTime()}, so {@code lock_until} is computed from
* each replica's own clock via {@code ClockProvider.now()}.
*
* <p>Used only by the clock-skew experiment. Do not copy it into anything real.
*
* <p>See docs/04-clock-skew.md.
*/
@Configuration(proxyBeanMethods = false)
@Profile("appclock")
@EnableSchedulerLock(defaultLockAtMostFor = "PT30S")
public class AppClockLockConfiguration {
@Bean
public LockProvider lockProvider(DataSource dataSource) {
return new JdbcTemplateLockProvider(JdbcTemplateLockProvider.Configuration.builder()
.withJdbcTemplate(new JdbcTemplate(dataSource))
.build());
}
}

View File

@@ -0,0 +1,39 @@
package com.ankurm.scheduling;
import java.time.Instant;
import java.util.List;
import java.util.Map;
import org.springframework.jdbc.core.JdbcTemplate;
import org.springframework.stereotype.Component;
/** Append-only record of who ran what and when, shared by all three replicas. */
@Component
public class ExecutionLog {
private final JdbcTemplate jdbc;
public ExecutionLog(JdbcTemplate jdbc) {
this.jdbc = jdbc;
}
public void record(String jobName, String instanceId, Instant startedAt) {
this.jdbc.update("insert into job_execution (job_name, instance_id, started_at) values (?, ?, ?)",
jobName, instanceId, java.sql.Timestamp.from(startedAt));
}
public List<Map<String, Object>> all() {
return this.jdbc.queryForList(
"select instance_id, started_at from job_execution order by started_at");
}
public int count() {
Integer n = this.jdbc.queryForObject("select count(*) from job_execution", Integer.class);
return (n != null) ? n : 0;
}
public void clear() {
this.jdbc.update("delete from job_execution");
this.jdbc.update("delete from shedlock");
}
}

View File

@@ -0,0 +1,45 @@
package com.ankurm.scheduling;
import javax.sql.DataSource;
import net.javacrumbs.shedlock.core.LockProvider;
import net.javacrumbs.shedlock.provider.jdbctemplate.JdbcTemplateLockProvider;
import net.javacrumbs.shedlock.spring.annotation.EnableSchedulerLock;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.Profile;
import org.springframework.jdbc.core.JdbcTemplate;
/**
* The entire difference between the two runs in docs/output/.
*
* <p>{@code defaultLockAtMostFor} has no default value in the annotation, so it must be supplied.
* That is deliberate on ShedLock's part: it is the answer to &ldquo;how long may this lock stay
* held if the holder dies without releasing it&rdquo;, and there is no safe guess.
*
* <p>{@code interceptMode} defaults to {@code PROXY_METHOD} in ShedLock 7. The older
* {@code PROXY_SCHEDULER} that most tutorials still show is deprecated &mdash; its own Javadoc
* says it &ldquo;requires a reflection hack to work well with Spring 6.2&rdquo;.
*
* <p>See docs/02-the-lock.md.
*/
@Configuration(proxyBeanMethods = false)
@Profile("locked")
@EnableSchedulerLock(defaultLockAtMostFor = "PT30S")
public class LockConfiguration {
/**
* {@code usingDbTime()} makes the database compute {@code lock_until}, so the lock survives
* clock skew between replicas. Without it, every replica writes a timestamp taken from its
* own clock, and a replica whose clock runs slow will consider a live lock expired.
* docs/output/clock-skew.txt is that experiment.
*/
@Bean
public LockProvider lockProvider(DataSource dataSource) {
return new JdbcTemplateLockProvider(JdbcTemplateLockProvider.Configuration.builder()
.withJdbcTemplate(new JdbcTemplate(dataSource))
.usingDbTime()
.build());
}
}

View File

@@ -0,0 +1,98 @@
package com.ankurm.scheduling;
import java.util.List;
import java.util.concurrent.ConcurrentSkipListSet;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.concurrent.atomic.AtomicInteger;
import org.springframework.context.annotation.Profile;
import org.springframework.scheduling.annotation.Scheduled;
import org.springframework.stereotype.Component;
/**
* Two scheduled methods sharing whatever scheduler the application has, plus one that always
* throws.
*
* <p>{@code spring.task.scheduling.pool.size} defaults to <strong>1</strong>. The interesting
* part is what that does to a {@code fixedRate} job when another job occupies the thread: it is
* not skipped. The missed ticks accumulate and are then executed back to back the moment the
* thread frees up. Counting executions therefore shows nothing; the evidence is in the gaps
* between them.
*
* <p>See docs/03-one-scheduler-thread.md.
*/
@Component
@Profile("poolprobe")
public class PoolProbeJob {
/** Millisecond timestamps of every fast() execution, in order. */
private final List<Long> fastAt = new CopyOnWriteArrayList<>();
private final AtomicInteger slowRuns = new AtomicInteger();
private final AtomicInteger throwingRuns = new AtomicInteger();
private final ConcurrentSkipListSet<String> schedulerThreads = new ConcurrentSkipListSet<>();
@Scheduled(fixedRate = 2000, initialDelay = 0)
public void slow() throws InterruptedException {
this.slowRuns.incrementAndGet();
this.schedulerThreads.add(Thread.currentThread().getName());
Thread.sleep(1800);
}
@Scheduled(fixedRate = 200, initialDelay = 0)
public void fast() {
this.fastAt.add(System.currentTimeMillis());
this.schedulerThreads.add(Thread.currentThread().getName());
}
/**
* Throws on every execution. A raw {@code ScheduledExecutorService} cancels a task after the
* first failure; Spring wraps scheduled methods in an error handler that logs and suppresses,
* so the schedule continues. Counted rather than assumed.
*/
@Scheduled(fixedRate = 300, initialDelay = 0)
public void throwing() {
this.throwingRuns.incrementAndGet();
throw new IllegalStateException("scheduled method #" + this.throwingRuns.get() + " failed");
}
public int fastRuns() {
return this.fastAt.size();
}
/** The longest interval the fast job went without running, in milliseconds. */
public long longestGapMillis() {
List<Long> at = List.copyOf(this.fastAt);
long worst = 0;
for (int i = 1; i < at.size(); i++) {
worst = Math.max(worst, at.get(i) - at.get(i - 1));
}
return worst;
}
/** Executions that started within 20 ms of the previous one: the catch-up burst. */
public long burstExecutions() {
List<Long> at = List.copyOf(this.fastAt);
long burst = 0;
for (int i = 1; i < at.size(); i++) {
if (at.get(i) - at.get(i - 1) < 20) {
burst++;
}
}
return burst;
}
public int slowRuns() {
return this.slowRuns.get();
}
public int throwingRuns() {
return this.throwingRuns.get();
}
public ConcurrentSkipListSet<String> schedulerThreads() {
return this.schedulerThreads;
}
}

View File

@@ -0,0 +1,54 @@
package com.ankurm.scheduling;
import java.time.Duration;
import java.time.Instant;
import net.javacrumbs.shedlock.spring.annotation.SchedulerLock;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.scheduling.annotation.Scheduled;
import org.springframework.stereotype.Component;
/**
* The job every distributed-cron article is really about: something that must happen once per
* tick across the whole cluster, not once per replica.
*
* <p>It records every execution in {@code job_execution}, tagged with the instance that ran it.
* Counting rows per tick is the measurement.
*
* <p>The {@code @SchedulerLock} annotation below is present in every profile. On its own it does
* nothing at all: it needs {@code @EnableSchedulerLock} to install the interceptor and a
* {@code LockProvider} bean to have somewhere to put the lock. Both live in
* {@link LockConfiguration}, which is only active under the {@code locked} profile. An
* application missing either of them starts cleanly, logs nothing, and runs the job on every
* replica &mdash; which is the failure this module exists to reproduce.
*/
@Component
public class ReportJob {
private static final Logger log = LoggerFactory.getLogger(ReportJob.class);
private final ExecutionLog executions;
private final String instanceId;
private final Duration work;
public ReportJob(ExecutionLog executions, @Value("${instance.id:unknown}") String instanceId,
@Value("${job.duration:PT0.2S}") Duration work) {
this.executions = executions;
this.instanceId = instanceId;
this.work = work;
}
@Scheduled(fixedRateString = "${job.rate:PT3S}")
@SchedulerLock(name = "nightlyReport", lockAtMostFor = "PT20S", lockAtLeastFor = "PT1S")
public void run() throws InterruptedException {
Instant startedAt = Instant.now();
log.info("nightlyReport running on {} at {}", this.instanceId, startedAt);
this.executions.record("nightlyReport", this.instanceId, startedAt);
Thread.sleep(this.work);
}
}

View File

@@ -0,0 +1,38 @@
package com.ankurm.scheduling;
import java.time.Clock;
import java.time.Duration;
import net.javacrumbs.shedlock.core.ClockProvider;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.scheduling.annotation.EnableScheduling;
/**
* Three replicas of this application run against one PostgreSQL database.
*
* <p>{@code @EnableScheduling} is here; {@code @EnableSchedulerLock} deliberately is not. It
* lives on {@link LockConfiguration}, which is {@code @Profile("locked")}. The scheduled job
* carries its {@code @SchedulerLock} annotation in both profiles, so the only difference between
* the run that executes three times and the run that executes once is whether one
* {@code @Configuration} class is active.
*
* <p>See docs/01-three-replicas-three-executions.md.
*/
@SpringBootApplication
@EnableScheduling
public class SchedulingApplication {
public static void main(String[] args) {
// -Dclock.skew=PT-40S shifts this replica's idea of "now" backwards by 40 seconds.
// ShedLock reads the wall clock through ClockProvider, so this is enough to simulate a
// machine whose NTP has drifted -- without needing root to change the system clock.
String skew = System.getProperty("clock.skew");
if (skew != null) {
ClockProvider.setClock(Clock.offset(Clock.systemUTC(), Duration.parse(skew)));
System.out.println("clock.skew applied: " + skew + " -> now=" + ClockProvider.now());
}
SpringApplication.run(SchedulingApplication.class, args);
}
}

View File

@@ -0,0 +1,24 @@
spring:
application:
name: scheduling
datasource:
url: ${DB_URL:jdbc:postgresql://127.0.0.1:55432/shedlockdemo}
username: ${DB_USER:app}
password: ${DB_PASSWORD:}
sql:
init:
mode: always
# spring.task.scheduling.pool.size defaults to 1. Left alone here on purpose: see
# docs/03-one-scheduler-thread.md for what that costs, measured.
instance:
id: ${INSTANCE_ID:local}
job:
rate: PT3S
duration: PT0.2S
logging:
level:
root: WARN
com.ankurm.scheduling: INFO
net.javacrumbs.shedlock: INFO

View File

@@ -0,0 +1,18 @@
-- Both tables are created by every replica at startup, so every statement is IF NOT EXISTS.
-- The shedlock table's shape is fixed by ShedLock: name, lock_until, locked_at, locked_by.
-- lock_until and locked_at must be timestamps; with usingDbTime() they are written by the
-- database, so their precision and time zone are the database's, not the JVM's.
create table if not exists shedlock (
name varchar(64) not null,
lock_until timestamp not null,
locked_at timestamp not null,
locked_by varchar(255) not null,
primary key (name)
);
create table if not exists job_execution (
id serial primary key,
job_name varchar(64) not null,
instance_id varchar(64) not null,
started_at timestamp not null
);

View File

@@ -0,0 +1,23 @@
package com.ankurm.scheduling;
import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Path;
/** Writes a transcript under docs/output/. */
final class Capture {
private Capture() {
}
static void write(String fileName, String heading, String body) {
Path dir = Path.of(System.getProperty("user.dir"), "docs", "output");
try {
Files.createDirectories(dir);
Files.writeString(dir.resolve(fileName), "== " + heading + " ==\n\n" + body + "\n");
}
catch (IOException ex) {
throw new IllegalStateException("could not write " + fileName, ex);
}
}
}

View File

@@ -0,0 +1,106 @@
package com.ankurm.scheduling;
import java.time.Clock;
import java.time.Duration;
import java.time.Instant;
import java.util.Optional;
import javax.sql.DataSource;
import net.javacrumbs.shedlock.core.ClockProvider;
import net.javacrumbs.shedlock.core.LockConfiguration;
import net.javacrumbs.shedlock.core.LockProvider;
import net.javacrumbs.shedlock.core.SimpleLock;
import net.javacrumbs.shedlock.provider.jdbctemplate.JdbcTemplateLockProvider;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.jdbc.core.JdbcTemplate;
import org.springframework.test.context.ActiveProfiles;
import static org.assertj.core.api.Assertions.assertThat;
/**
* What {@code usingDbTime()} is actually for.
*
* <p>Driving the {@code LockProvider} directly rather than through three replicas, because the
* three-replica run is a race and a race cannot prove a negative. Here the two acquisitions are
* ordered by the test, and the only thing that changes between them is what the second caller
* believes the time to be.
*
* <p>See docs/04-clock-skew.md.
*/
@SpringBootTest(properties = "job.rate=PT1H")
@ActiveProfiles("locked")
class ClockSkewTest {
private static final String LOCK_NAME = "skewProbe";
@Autowired
private JdbcTemplate jdbc;
@AfterEach
void resetClock() {
ClockProvider.setClock(Clock.systemUTC());
this.jdbc.update("delete from shedlock where name = ?", LOCK_NAME);
}
@Test
void withAppTimeAFastClockStealsALiveLock() {
LockProvider provider = provider(false);
Optional<SimpleLock> first = acquire(provider);
assertThat(first).isPresent();
// A second node whose clock is 40 seconds fast, asking for the same lock while the first
// holder is still working.
ClockProvider.setClock(Clock.offset(Clock.systemUTC(), Duration.ofSeconds(40)));
Optional<SimpleLock> second = acquire(provider);
assertThat(second).isPresent();
Capture.write("clock-skew.txt", "One lock, two holders: what usingDbTime() prevents",
"""
lockAtMostFor = 30s, both callers ask for the same lock name.
JdbcTemplateLockProvider WITHOUT usingDbTime()
node with a correct clock : acquired
node with a clock 40s fast : ACQUIRED -- two holders at the same time
JdbcTemplateLockProvider WITH usingDbTime()
node with a correct clock : acquired
node with a clock 40s fast : refused
Without usingDbTime() the expiry comparison happens against the calling
JVM's clock, so a node that is ahead by more than lockAtMostFor considers
every live lock expired. With it, both the write and the comparison happen
in the database, and there is only one clock in the system.
""");
}
@Test
void withDbTimeTheSameFastClockIsRefused() {
LockProvider provider = provider(true);
assertThat(acquire(provider)).isPresent();
ClockProvider.setClock(Clock.offset(Clock.systemUTC(), Duration.ofSeconds(40)));
assertThat(acquire(provider)).isEmpty();
}
private Optional<SimpleLock> acquire(LockProvider provider) {
return provider.lock(new LockConfiguration(ClockProvider.now(), LOCK_NAME,
Duration.ofSeconds(30), Duration.ZERO));
}
private LockProvider provider(boolean dbTime) {
DataSource dataSource = this.jdbc.getDataSource();
JdbcTemplateLockProvider.Configuration.Builder builder =
JdbcTemplateLockProvider.Configuration.builder()
.withJdbcTemplate(new JdbcTemplate(dataSource));
if (dbTime) {
builder = builder.usingDbTime();
}
return new JdbcTemplateLockProvider(builder.build());
}
}

View File

@@ -0,0 +1,37 @@
package com.ankurm.scheduling;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.ActiveProfiles;
import static org.assertj.core.api.Assertions.assertThat;
/** The same three jobs with four scheduler threads. One property; the schedule is kept. */
@SpringBootTest(properties = { "job.rate=PT1H", "spring.task.scheduling.pool.size=4" })
@ActiveProfiles("poolprobe")
class LargerSchedulerPoolTest {
@Autowired
private PoolProbeJob job;
@Test
void fourThreadsKeepTheFastJobOnItsSchedule() throws Exception {
Thread.sleep(8000);
assertThat(this.job.longestGapMillis()).isLessThan(600);
assertThat(this.job.burstExecutions()).isZero();
assertThat(this.job.throwingRuns()).isGreaterThan(15);
Capture.write("scheduler-pool-4.txt", "spring.task.scheduling.pool.size=4",
SingleSchedulerThreadTest.report(this.job) + """
throwing() kept its schedule after every failure. Spring wraps a scheduled
method in TaskUtils.LOG_AND_SUPPRESS_ERROR_HANDLER, so each exception is
logged by o.s.s.s.TaskUtils$LoggingErrorHandler as "Unexpected error
occurred in scheduled task" and then discarded. A raw
ScheduledExecutorService would have cancelled the task at the first one.
""");
}
}

View File

@@ -0,0 +1,52 @@
package com.ankurm.scheduling;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.ActiveProfiles;
import static org.assertj.core.api.Assertions.assertThat;
/**
* The Boot default, {@code spring.task.scheduling.pool.size=1}.
*
* <p>The naive expectation is that the 200 ms job runs fewer times. It does not: {@code fixedRate}
* accumulates its missed ticks and fires them in a burst when the thread is released. The damage
* is to the schedule, not to the count, which is why this is so easy to miss in a metric.
*/
@SpringBootTest(properties = { "job.rate=PT1H", "spring.task.scheduling.pool.size=1" })
@ActiveProfiles("poolprobe")
class SingleSchedulerThreadTest {
@Autowired
private PoolProbeJob job;
@Test
void oneSlowJobWrecksTheOtherJobsSchedule() throws Exception {
Thread.sleep(8000);
assertThat(this.job.schedulerThreads()).hasSize(1);
assertThat(this.job.longestGapMillis()).isGreaterThan(1000);
assertThat(this.job.burstExecutions()).isGreaterThan(3);
Capture.write("scheduler-pool-1.txt", "spring.task.scheduling.pool.size=1 (the default)",
report(this.job));
}
static String report(PoolProbeJob job) {
return """
over 8 seconds, three @Scheduled methods on one application
slow() fixedRate 2000 ms, sleeps 1800 ms : %d executions
fast() fixedRate 200 ms : %d executions
throwing() fixedRate 300 ms, always throws : %d executions
distinct scheduler threads : %d %s
longest gap between two fast() executions : %d ms (200 ms was the schedule)
fast() executions that started within 20 ms
of the previous one (the catch-up burst) : %d
""".formatted(job.slowRuns(), job.fastRuns(), job.throwingRuns(),
job.schedulerThreads().size(), job.schedulerThreads(),
job.longestGapMillis(), job.burstExecutions());
}
}