[SQL] FOR UPDATE SKIP LOCKED is not skipping a record that should be skipped

I would like to build a queue of Articles where each article has a last_seen_at. User arrives on web page, server ORDERs Articles by last_seen_at ASC, selects the first and returns to the browser. The server updates last_seen_at to be NOW() before returning to the browser.

In this way an Article is moved as last in the queue if it was just delivered.

For this I use FOR UPDATE SKIP LOCKED.

The problem is that under heavy load and concurrent request in a few milliseconds we return the same article to two different users.

The query is

SELECT * INTO rec
FROM articles
ORDER BY last_seen_at ASC NULLS FIRST
LIMIT 1
FOR UPDATE SKIP LOCKED;

UPDATE articles SET last_seen_at = NOW() WHERE id = rec.id;


and the way to reproduce it is by running this script. It simulates 10 different clients that are executing requests with psql. Actual servers have more, so I tried to bring the script to bash, psql and SQL.

The idea is that 10 clients will request from the table of 20 records at almost the same time and each client should receive a unique article to read. There should be no duplicates.

#!/bin/bash

# Define database variables
DB_NAME="article_db"
DB_USER="...fill here..."
DB_HOST="localhost" # Adjust as needed
DB_PORT="5432" # Adjust as needed

# Drop the database
echo "Dropping database: $DB_NAME"
psql -U $DB_USER -c "DROP DATABASE IF EXISTS $DB_NAME;" postgres

echo "Database $DB_NAME has been removed."

# Create the database
echo "Creating database: $DB_NAME"
psql -U $DB_USER -c "CREATE DATABASE $DB_NAME;" postgres


psql -U $DB_USER -c "

CREATE TABLE articles (
id SERIAL PRIMARY KEY,
title VARCHAR(255),
content TEXT,
last_seen_at TIMESTAMPTZ,
created_at TIMESTAMPTZ DEFAULT NOW(),
updated_at TIMESTAMPTZ DEFAULT NOW()
);

INSERT INTO articles (title, content, last_seen_at)
VALUES
('Article 1', 'This is the content of article 1.', NOW()),
('Article 2', 'This is the content of article 2.', NOW()),
('Article 3', 'This is the content of article 3.', NOW()),
('Article 4', 'This is the content of article 4.', NOW()),
('Article 5', 'This is the content of article 5.', NOW()),
('Article 6', 'This is the content of article 6.', NOW()),
('Article 7', 'This is the content of article 7.', NOW()),
('Article 8', 'This is the content of article 8.', NOW()),
('Article 9', 'This is the content of article 9.', NOW()),
('Article 10', 'This is the content of article 10.', NOW()),
('Article 11', 'This is the content of article 11.', NOW()),
('Article 12', 'This is the content of article 12.', NOW()),
('Article 13', 'This is the content of article 13.', NOW()),
('Article 14', 'This is the content of article 14.', NOW()),
('Article 15', 'This is the content of article 15.', NOW()),
('Article 16', 'This is the content of article 16.', NOW()),
('Article 17', 'This is the content of article 17.', NOW()),
('Article 18', 'This is the content of article 18.', NOW()),
('Article 19', 'This is the content of article 19.', NOW()),
('Article 20', 'This is the content of article 20.', NOW());

" $DB_NAME

echo "" > output.txt
echo $(psql --version) >> output.txt
for i in {0..15}; do
echo "Run $i" >> output.txt
x=0.01
y=0.2
sleep_time=$(awk -v min=$x -v max=$y 'BEGIN{srand(); print min+rand()*(max-min)}')
sleep $sleep_time # just so that NOW() returns different values and not close to each other

for n in {0..9}; do
psql -U $DB_USER -c "
DO \$\$
DECLARE
rec RECORD;
BEGIN
-- Select and lock the row
SELECT * INTO rec
FROM articles
ORDER BY last_seen_at ASC NULLS FIRST
LIMIT 1
FOR UPDATE SKIP LOCKED;

UPDATE articles SET last_seen_at = NOW() WHERE id = rec.id;

-- Return the result after commit
RAISE NOTICE 'ID: %, Title: %, Last: %', rec.id, rec.title, rec.last_seen_at;
END \$\$;
" $DB_NAME 2>> output.txt &
done
wait
echo "Run $i done"
done


When you run the script what happens is


psql (PostgreSQL) 12.12
Run 0
NOTICE: ID: 1, Title: Article 1, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 3, Title: Article 3, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 6, Title: Article 6, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 7, Title: Article 7, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 8, Title: Article 8, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 9, Title: Article 9, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 10, Title: Article 10, Last: 2024-10-03 23:07:55.191153+03
Run 1
NOTICE: ID: 11, Title: Article 11, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 12, Title: Article 12, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 13, Title: Article 13, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 18, Title: Article 18, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 19, Title: Article 19, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 20, Title: Article 20, Last: 2024-10-03 23:07:55.191153+03
NOTICE: ID: 17, Title: Article 17, Last: 2024-10-03 23:07:55.191153+03
Run 2
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:55.357+03
NOTICE: ID: 1, Title: Article 1, Last: 2024-10-03 23:07:55.357631+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:55.360134+03
NOTICE: ID: 3, Title: Article 3, Last: 2024-10-03 23:07:55.366221+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:55.369527+03
NOTICE: ID: 6, Title: Article 6, Last: 2024-10-03 23:07:55.370643+03
NOTICE: ID: 7, Title: Article 7, Last: 2024-10-03 23:07:55.379598+03
NOTICE: ID: 8, Title: Article 8, Last: 2024-10-03 23:07:55.38012+03
NOTICE: ID: 9, Title: Article 9, Last: 2024-10-03 23:07:55.380929+03
NOTICE: ID: 10, Title: Article 10, Last: 2024-10-03 23:07:55.381026+03
Run 3
NOTICE: ID: 11, Title: Article 11, Last: 2024-10-03 23:07:55.529283+03
NOTICE: ID: 12, Title: Article 12, Last: 2024-10-03 23:07:55.531521+03
NOTICE: ID: 13, Title: Article 13, Last: 2024-10-03 23:07:55.53443+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:55.539379+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:55.544098+03
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:55.545991+03
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:55.889783+03
NOTICE: ID: 18, Title: Article 18, Last: 2024-10-03 23:07:55.552443+03
NOTICE: ID: 19, Title: Article 19, Last: 2024-10-03 23:07:55.55334+03
NOTICE: ID: 20, Title: Article 20, Last: 2024-10-03 23:07:55.553517+03
Run 4
NOTICE: ID: 17, Title: Article 17, Last: 2024-10-03 23:07:55.553575+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:55.704585+03
NOTICE: ID: 1, Title: Article 1, Last: 2024-10-03 23:07:55.706418+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:55.709828+03
NOTICE: ID: 3, Title: Article 3, Last: 2024-10-03 23:07:55.711804+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:55.714998+03
NOTICE: ID: 6, Title: Article 6, Last: 2024-10-03 23:07:55.720595+03
NOTICE: ID: 7, Title: Article 7, Last: 2024-10-03 23:07:55.72123+03
NOTICE: ID: 8, Title: Article 8, Last: 2024-10-03 23:07:55.721629+03
NOTICE: ID: 10, Title: Article 10, Last: 2024-10-03 23:07:55.721857+03
Run 5
NOTICE: ID: 9, Title: Article 9, Last: 2024-10-03 23:07:55.721988+03
NOTICE: ID: 12, Title: Article 12, Last: 2024-10-03 23:07:55.871198+03
NOTICE: ID: 11, Title: Article 11, Last: 2024-10-03 23:07:55.871329+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:55.878223+03
NOTICE: ID: 13, Title: Article 13, Last: 2024-10-03 23:07:55.873865+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:55.881956+03
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:55.890476+03
NOTICE: ID: 18, Title: Article 18, Last: 2024-10-03 23:07:55.890876+03
NOTICE: ID: 19, Title: Article 19, Last: 2024-10-03 23:07:55.892448+03
NOTICE: ID: 20, Title: Article 20, Last: 2024-10-03 23:07:55.892666+03
Run 6
NOTICE: ID: 17, Title: Article 17, Last: 2024-10-03 23:07:56.045753+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:56.046676+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:56.053627+03
NOTICE: ID: 1, Title: Article 1, Last: 2024-10-03 23:07:56.049792+03
NOTICE: ID: 3, Title: Article 3, Last: 2024-10-03 23:07:56.059395+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:56.062333+03
NOTICE: ID: 7, Title: Article 7, Last: 2024-10-03 23:07:56.064246+03
NOTICE: ID: 6, Title: Article 6, Last: 2024-10-03 23:07:56.064377+03
NOTICE: ID: 8, Title: Article 8, Last: 2024-10-03 23:07:56.064599+03
NOTICE: ID: 10, Title: Article 10, Last: 2024-10-03 23:07:56.06874+03
Run 7
NOTICE: ID: 12, Title: Article 12, Last: 2024-10-03 23:07:56.303647+03
NOTICE: ID: 9, Title: Article 9, Last: 2024-10-03 23:07:56.304069+03
NOTICE: ID: 11, Title: Article 11, Last: 2024-10-03 23:07:56.310685+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:56.314391+03
NOTICE: ID: 13, Title: Article 13, Last: 2024-10-03 23:07:56.314454+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:56.315747+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:56.8011+03
NOTICE: ID: 18, Title: Article 18, Last: 2024-10-03 23:07:56.317306+03
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:56.317362+03
NOTICE: ID: 19, Title: Article 19, Last: 2024-10-03 23:07:56.317796+03
Run 8
NOTICE: ID: 20, Title: Article 20, Last: 2024-10-03 23:07:56.317888+03
NOTICE: ID: 17, Title: Article 17, Last: 2024-10-03 23:07:56.546232+03
NOTICE: ID: 1, Title: Article 1, Last: 2024-10-03 23:07:56.556373+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:56.549424+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:56.559143+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:57.028894+03
NOTICE: ID: 3, Title: Article 3, Last: 2024-10-03 23:07:56.560479+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:56.561629+03
NOTICE: ID: 7, Title: Article 7, Last: 2024-10-03 23:07:56.563405+03
NOTICE: ID: 6, Title: Article 6, Last: 2024-10-03 23:07:56.564448+03
Run 9
NOTICE: ID: 8, Title: Article 8, Last: 2024-10-03 23:07:56.565825+03
NOTICE: ID: 10, Title: Article 10, Last: 2024-10-03 23:07:56.566152+03
NOTICE: ID: 12, Title: Article 12, Last: 2024-10-03 23:07:56.783754+03
NOTICE: ID: 9, Title: Article 9, Last: 2024-10-03 23:07:56.783821+03
NOTICE: ID: 11, Title: Article 11, Last: 2024-10-03 23:07:56.791792+03
NOTICE: ID: 13, Title: Article 13, Last: 2024-10-03 23:07:56.792547+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:56.79418+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:57.169286+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:56.801556+03
NOTICE: ID: 18, Title: Article 18, Last: 2024-10-03 23:07:56.801921+03
Run 10
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:56.80328+03
NOTICE: ID: 19, Title: Article 19, Last: 2024-10-03 23:07:56.803508+03
NOTICE: ID: 20, Title: Article 20, Last: 2024-10-03 23:07:57.021593+03
NOTICE: ID: 17, Title: Article 17, Last: 2024-10-03 23:07:57.02499+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:57.033416+03
NOTICE: ID: 1, Title: Article 1, Last: 2024-10-03 23:07:57.036014+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:57.039942+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:57.043892+03
NOTICE: ID: 3, Title: Article 3, Last: 2024-10-03 23:07:57.044432+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:57.295768+03
Run 11
NOTICE: ID: 6, Title: Article 6, Last: 2024-10-03 23:07:57.046077+03
NOTICE: ID: 10, Title: Article 10, Last: 2024-10-03 23:07:57.144911+03
NOTICE: ID: 7, Title: Article 7, Last: 2024-10-03 23:07:57.045291+03
NOTICE: ID: 8, Title: Article 8, Last: 2024-10-03 23:07:57.146934+03
NOTICE: ID: 12, Title: Article 12, Last: 2024-10-03 23:07:57.151276+03
NOTICE: ID: 9, Title: Article 9, Last: 2024-10-03 23:07:57.157833+03
NOTICE: ID: 11, Title: Article 11, Last: 2024-10-03 23:07:57.163592+03
NOTICE: ID: 13, Title: Article 13, Last: 2024-10-03 23:07:57.167025+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:57.169716+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:57.170998+03
Run 12
NOTICE: ID: 18, Title: Article 18, Last: 2024-10-03 23:07:57.171116+03
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:57.275763+03
NOTICE: ID: 19, Title: Article 19, Last: 2024-10-03 23:07:57.282054+03
NOTICE: ID: 20, Title: Article 20, Last: 2024-10-03 23:07:57.289475+03
NOTICE: ID: 17, Title: Article 17, Last: 2024-10-03 23:07:57.292438+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:57.294022+03
NOTICE: ID: 1, Title: Article 1, Last: 2024-10-03 23:07:57.2951+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:57.295277+03
NOTICE: ID: 3, Title: Article 3, Last: 2024-10-03 23:07:57.295999+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:57.29623+03
Run 13
NOTICE: ID: 8, Title: Article 8, Last: 2024-10-03 23:07:57.393965+03
NOTICE: ID: 7, Title: Article 7, Last: 2024-10-03 23:07:57.395886+03
NOTICE: ID: 6, Title: Article 6, Last: 2024-10-03 23:07:57.398183+03
NOTICE: ID: 10, Title: Article 10, Last: 2024-10-03 23:07:57.404+03
NOTICE: ID: 12, Title: Article 12, Last: 2024-10-03 23:07:57.410518+03
NOTICE: ID: 13, Title: Article 13, Last: 2024-10-03 23:07:57.419476+03
NOTICE: ID: 9, Title: Article 9, Last: 2024-10-03 23:07:57.419919+03
NOTICE: ID: 11, Title: Article 11, Last: 2024-10-03 23:07:57.420215+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:57.421694+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:57.421805+03
Run 14
NOTICE: ID: 18, Title: Article 18, Last: 2024-10-03 23:07:57.522213+03
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:57.524602+03
NOTICE: ID: 19, Title: Article 19, Last: 2024-10-03 23:07:57.531331+03
NOTICE: ID: 20, Title: Article 20, Last: 2024-10-03 23:07:57.533905+03
NOTICE: ID: 17, Title: Article 17, Last: 2024-10-03 23:07:57.538787+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:57.53948+03
NOTICE: ID: 1, Title: Article 1, Last: 2024-10-03 23:07:57.540906+03
NOTICE: ID: 3, Title: Article 3, Last: 2024-10-03 23:07:57.540984+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:57.541091+03
NOTICE: ID: 5, Title: Article 5, Last: 2024-10-03 23:07:57.541513+03
Run 15
NOTICE: ID: 8, Title: Article 8, Last: 2024-10-03 23:07:57.642186+03
NOTICE: ID: 6, Title: Article 6, Last: 2024-10-03 23:07:57.645733+03
NOTICE: ID: 7, Title: Article 7, Last: 2024-10-03 23:07:57.6465+03
NOTICE: ID: 10, Title: Article 10, Last: 2024-10-03 23:07:57.654263+03
NOTICE: ID: 12, Title: Article 12, Last: 2024-10-03 23:07:57.659976+03
NOTICE: ID: 13, Title: Article 13, Last: 2024-10-03 23:07:57.661056+03
NOTICE: ID: 9, Title: Article 9, Last: 2024-10-03 23:07:57.661537+03
NOTICE: ID: 11, Title: Article 11, Last: 2024-10-03 23:07:57.662008+03
NOTICE: ID: 14, Title: Article 14, Last: 2024-10-03 23:07:57.663009+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:57.663025+03


We do 15 runs and in this 15 runs of requesting 10 articles in parallel, we get: In run 3, article 16 was returned two times

NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:55.545991+03
NOTICE: ID: 16, Title: Article 16, Last: 2024-10-03 23:07:55.889783+03


In run 7 article 15 was returned two times

NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:56.315747+03
NOTICE: ID: 15, Title: Article 15, Last: 2024-10-03 23:07:56.8011+03


In run 8 article 4 was returned two times

NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:56.549424+03
NOTICE: ID: 2, Title: Article 2, Last: 2024-10-03 23:07:56.559143+03
NOTICE: ID: 4, Title: Article 4, Last: 2024-10-03 23:07:57.028894+03


and so on.

It happens about 5-10 percent of the cases.

What I fail to understand is why FOR UPDATE SKIP LOCKED is not working the way I would expect it to work - lock a row and if others try to lock it they should move to a different row.

Thanks

Continue reading...