Replication / catch-up Processing: Node(3800k 111.8k/s) stuck forever

[stouch]

Describe the bug

Processing of replication catch-up is stuck in our Nominatim 4.4 container (we didn't upgrade its database/catch-up since 1 year).
When we started the upgrade, it stayed stuck for dozen of hours (forever actually) on this log :

2025-02-16 15:44:38: Using project directory: /nominatim
2025-02-16 15:45:26  osm2pgsql version 1.11.0
2025-02-16 15:45:26  Database version: 14.11 (Ubuntu 14.11-0ubuntu0.22.04.1)
2025-02-16 15:45:26  PostGIS version: 3.2
2025-02-16 15:45:26  No properties found in database from previous import.
Processing: Node(3800k 111.8k/s) Way(0k 0.00k/s) Relation(0 0.0/s)

Solution

Thanks to this thread osm-search/Nominatim#3445 (comment), I've been able to fix it with :

Starting the docker container without the catch-up enabled (UPDATE_MODE=none), and then I entered in the instance to run :

docker exec -it nominatim sudo -u nominatim /bin/bash
NOMINATIM_REPLICATION_MAX_DIFF=10000 nohup nominatim replication --project-dir /nominatim --catch-up &

It fixed the issue (for now, at least, the processing is going further.. :

nominatim@7c212aa8874d:/app$ tail -f /home/nominatim/nohup.out 
2025-02-16 16:03:21: Using project directory: /nominatim
2025-02-16 16:21:57  osm2pgsql version 1.11.0
2025-02-16 16:21:57  Database version: 14.11 (Ubuntu 14.11-0ubuntu0.22.04.1)
2025-02-16 16:21:57  PostGIS version: 3.2
2025-02-16 16:21:57  No properties found in database from previous import.
Processing: Node(78720k 33.4k/s) Way(0k 0.00k/s) Relation(0 0.0/s)

🙌

[stouch]

OK , that seems to be a fail ... Finally it's stuck again at :

nominatim@7c212aa8874d:/app$ tail -f /home/nominatim/nohup.out 
2025-02-16 16:03:21: Using project directory: /nominatim
2025-02-16 16:21:57  osm2pgsql version 1.11.0
2025-02-16 16:21:57  Database version: 14.11 (Ubuntu 14.11-0ubuntu0.22.04.1)
2025-02-16 16:21:57  PostGIS version: 3.2
2025-02-16 16:21:57  No properties found in database from previous import.
Processing: Node(85780k 34.2k/s) Way(0k 0.00k/s) Relation(0 0.0/s)

I gonna wait for few hours to be sure and just stop the catch-up... @lonvia have you got any ideas?

Here is the ps aux inside the container right now :

nominatim@7c212aa8874d:/app$ ps aux 
USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root           1  0.0  0.0   4364   384 ?        Ss   15:58   0:00 /bin/bash -ex /app/start.sh
postgres      36  0.0  0.2 2241480 66432 ?       Ss   15:58   0:00 /usr/lib/postgresql/14/bin/postgres -D /var/lib/postgresql/14/main -c config_file=/etc/postgresql/14/main/postgresql.conf
postgres      38  0.0  0.2 2242832 66960 ?       Ss   15:58   0:00 postgres: 14/main: checkpointer 
postgres      39  0.3  7.0 2241616 2131088 ?     Ss   15:58   0:15 postgres: 14/main: background writer 
postgres      40  0.0  0.0 2241480 20368 ?       Ss   15:58   0:04 postgres: 14/main: walwriter 
postgres      41  0.0  0.0 2242144 18448 ?       Ss   15:58   0:00 postgres: 14/main: autovacuum launcher 
postgres      42  0.0  0.0  73060  4624 ?        Ss   15:58   0:00 postgres: 14/main: stats collector 
postgres      43  0.0  0.0 2241912 5904 ?        Ss   15:58   0:00 postgres: 14/main: logical replication launcher 
root          81  0.0  0.0 215984  9488 ?        Ss   15:58   0:00 /usr/sbin/apache2 -k start
root          84  0.0  0.0   2892   128 ?        S    15:58   0:00 /bin/sh -c /usr/bin/rotatelogs -n 7 /var/log/apache2/error.log 86400
root          85  0.0  0.0   2892   128 ?        S    15:58   0:00 /bin/sh -c /usr/bin/rotatelogs -n 7 /var/log/apache2/access.log 86400
root          86  0.0  0.0   3092   256 ?        S    15:58   0:00 /usr/bin/rotatelogs -n 7 /var/log/apache2/error.log 86400
root          87  0.0  0.0   3100   384 ?        S    15:58   0:00 /usr/bin/rotatelogs -n 7 /var/log/apache2/access.log 86400
www-data      88  0.3  0.0 222188 22120 ?        S    15:58   0:13 /usr/sbin/apache2 -k start
www-data      89  0.3  0.0 222196 20968 ?        S    15:58   0:14 /usr/sbin/apache2 -k start
www-data      90  0.3  0.0 222212 21224 ?        S    15:58   0:15 /usr/sbin/apache2 -k start
www-data      92  0.2  0.0 222048 21352 ?        S    15:58   0:12 /usr/sbin/apache2 -k start
postgres      93  1.1  7.0 2284200 2110312 ?     Ss   15:58   0:53 postgres: 14/main: www-data nominatim [local] idle
www-data      98  0.2  0.0 222000 20456 ?        S    15:58   0:11 /usr/sbin/apache2 -k start
postgres     100  1.2  7.1 2272812 2161912 ?     Ss   15:58   0:58 postgres: 14/main: www-data nominatim [local] idle
www-data     101  0.2  0.0 222084 20712 ?        S    15:58   0:12 /usr/sbin/apache2 -k start
postgres     102  2.6  7.1 2267188 2156816 ?     Ss   15:58   1:56 postgres: 14/main: www-data nominatim [local] idle
postgres     103  3.2  7.1 2262972 2152672 ?     Ss   15:58   2:24 postgres: 14/main: www-data nominatim [local] idle
root         104  0.0  0.0   2824   384 ?        S    15:58   0:00 tail -Fv /var/log/postgresql/postgresql-14-main.log /var/log/apache2/access.log /var/log/apache2/error.log /var/log/replication.log
root         105  0.0  0.0   7240   640 ?        S    15:58   0:00 sudo -H -E -u nominatim nominatim admin --warm
nominat+     106  0.0  0.1  69984 43736 ?        S    15:58   0:01 python3 /usr/local/bin/nominatim admin --warm
postgres     107 63.1  7.5 2357196 2264932 ?     Rs   15:58  46:57 postgres: 14/main: nominatim nominatim [local] SELECT
postgres     109  2.8  7.1 2271116 2160816 ?     Ss   15:59   2:05 postgres: 14/main: www-data nominatim [local] idle
postgres     119  0.1  3.0 2271212 908084 ?      Ss   15:59   0:08 postgres: 14/main: www-data nominatim [local] idle
www-data     126  0.3  0.0 222032 21608 ?        S    16:00   0:13 /usr/sbin/apache2 -k start
postgres     128  3.1  7.1 2271372 2163860 ?     Ss   16:01   2:14 postgres: 14/main: www-data nominatim [local] idle
www-data     140  0.2  0.0 221904 20456 ?        S    16:01   0:11 /usr/sbin/apache2 -k start
postgres     142  0.1  3.0 2258840 911948 ?      Ss   16:02   0:08 postgres: 14/main: www-data nominatim [local] idle
nominat+     145 19.7 20.1 6260252 6050480 ?     Sl   16:03  13:49 python3 /usr/local/bin/nominatim replication --project-dir /nominatim --catch-up
root         186  0.0  0.0   7240  1280 pts/2    Rs+  16:09   0:00 sudo -u nominatim /bin/bash
root         191  0.0  0.0   7240  1332 pts/3    Ss   16:09   0:00 sudo -u nominatim /bin/bash
nominat+     192  0.0  0.0   7636  2816 pts/3    S    16:09   0:00 /bin/bash
www-data     227  0.2  0.0 221872 20712 ?        S    16:14   0:09 /usr/sbin/apache2 -k start
postgres     231  4.9  7.2 2271420 2165060 ?     Ss   16:15   2:50 postgres: 14/main: www-data nominatim [local] idle
postgres     249  0.0  0.1 2242532 33040 ?       Ss   16:21   0:00 postgres: 14/main: nominatim nominatim [local] idle
nominat+     250 14.2  7.6 94936976 2284644 ?    Sl   16:21   7:18 /usr/local/lib/nominatim/osm2pgsql --slim --log-progress true --number-processes 1 --cache 2000 --style /usr/local/etc/nominatim/styles/import-custom.lua --output flex --append --flat-nodes /n
postgres     253 13.9  0.3 2312224 98996 ?       Rs   16:21   7:08 postgres: 14/main: nominatim nominatim [local] INSERT
postgres     255  0.0  0.0 2242408 10768 ?       Ss   16:21   0:00 postgres: 14/main: nominatim nominatim [local] idle
postgres     256  0.0  0.0 2242696 18576 ?       Ss   16:21   0:00 postgres: 14/main: nominatim nominatim [local] idle
postgres     257  0.0  0.0 2242412 11920 ?       Ss   16:21   0:00 postgres: 14/main: nominatim nominatim [local] idle
postgres     259 49.3 10.1 3153820 3064808 ?     Ss   16:21  25:18 postgres: 14/main: nominatim nominatim [local] COPY
www-data     296  0.2  0.0 221688 20712 ?        S    16:38   0:04 /usr/sbin/apache2 -k start
postgres     297  0.1  1.5 2270920 455688 ?      Ss   16:38   0:03 postgres: 14/main: www-data nominatim [local] idle
root         341  0.0  0.0   7240  3200 pts/0    Ss+  16:59   0:00 sudo -u nominatim /bin/bash
root         347  0.0  0.0   7240  1972 pts/1    Ss   16:59   0:00 sudo -u nominatim /bin/bash
nominat+     348  0.0  0.0   7636  3328 pts/1    S    16:59   0:00 /bin/bash
nominat+     355  0.0  0.0   5804  1664 pts/1    S+   17:01   0:00 tail -f /home/nominatim/nohup.out
nominat+     382  0.0  0.0  10072  3200 pts/3    R+   17:13   0:00 ps aux

The stuck queries :

nominatim=# select *
from pg_stat_activity;
 datid |  datname  | pid | leader_pid | usesysid |  usename  |      application_name      | client_addr | client_hostname | client_port |         backend_start         |          xact_start           |          query_start          |         state_change          | wait_event_type |     wait_event      | state  | backend_xid | backend_xmin | query_id |                                                                                               
                                                                                                                                                                                       query                                                                                                                                                                                                                                                                     
                  |         backend_type         
-------+-----------+-----+------------+----------+-----------+----------------------------+-------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-------------------------------+-----------------+---------------------+--------+-------------+--------------+----------+-----------------------------------------------------------------------------------------------
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
------------------+------------------------------
       |           |  41 |            |          |           |                            |             |                 |             | 2025-02-16 15:58:27.770721+00 |                               |                               |                               | Activity        | AutoVacuumMain      |        |             |              |          |                                                                                               
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | autovacuum launcher
       |           |  43 |            |       10 | postgres  |                            |             |                 |             | 2025-02-16 15:58:27.773022+00 |                               |                               |                               | Activity        | LogicalLauncherMain |        |             |              |          |                                                                                               
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | logical replication launcher
 16386 | nominatim |  93 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 15:58:34.5023+00   |                               | 2025-02-16 17:16:40.480283+00 | 2025-02-16 17:16:40.480297+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_00002174                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 107 |            |    16384 | nominatim |                            |             |                 |          -1 | 2025-02-16 15:58:52.771189+00 | 2025-02-16 17:15:30.890635+00 | 2025-02-16 17:15:31.109418+00 | 2025-02-16 17:15:31.109428+00 |                 |                     | active |             |     21515079 |          | SELECT places.place_id, places.osm_type, places.osm_id, places.name, places.class, places.type
, places.address, places.extratags, places.housenumber, places.postcode, places.country_code, places.importance, places.wikipedia, places.parent_place_id, places.rank_address, places.rank_search, ST_AsEWKB(places.centroid) AS centroid, places.linked_place_id, places.admin_level, places.distance AS distance, ST_AsEWKB(ST_Expand(places.geometry, $1::integer)) AS bbox                                                                                  
                 +| client backend
       |           |     |            |          |           |                            |             |                 |             |                               |                               |                               |                               |                 |                     |        |             |              |          | FROM (SELECT placex.place_id AS place_id, placex.parent_place_id AS parent_place_id, placex.li
nked_place_id AS linked_place_id, placex.importance AS importance, placex.indexed_date AS indexed_date, placex.rank_address AS rank_address, placex.rank_search AS rank_search, placex.indexed_status AS indexed_status, placex.osm_type AS osm_type, placex.osm_id AS osm_id, placex.class AS class, placex.type AS type, placex.admin_level AS admin_level, placex.name AS name, placex.address AS address, placex.extratags AS extratags, placex.geometry AS g
eometry, placex.w | 
 16386 | nominatim | 100 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 15:58:49.25316+00  |                               | 2025-02-16 17:16:14.405678+00 | 2025-02-16 17:16:14.405692+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_000024ec                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 102 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 15:58:50.665152+00 |                               | 2025-02-16 17:16:43.246838+00 | 2025-02-16 17:16:43.246853+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_00001c6f                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 103 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 15:58:50.924787+00 |                               | 2025-02-16 17:16:20.59576+00  | 2025-02-16 17:16:20.59577+00  | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_000026e8                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 385 |            |    16384 | nominatim | psql                       |             |                 |          -1 | 2025-02-16 17:13:57.451952+00 | 2025-02-16 17:16:45.544424+00 | 2025-02-16 17:16:45.544424+00 | 2025-02-16 17:16:45.544426+00 |                 |                     | active |             |     21515079 |          | select *                                                                                      
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                 +| client backend
       |           |     |            |          |           |                            |             |                 |             |                               |                               |                               |                               |                 |                     |        |             |              |          | from pg_stat_activity;                                                                        
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | 
 16386 | nominatim | 109 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 15:59:11.492118+00 |                               | 2025-02-16 17:16:26.735871+00 | 2025-02-16 17:16:26.735882+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_00001980                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 119 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 15:59:16.575469+00 |                               | 2025-02-16 17:16:13.230474+00 | 2025-02-16 17:16:13.230493+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_00001d22                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 128 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 16:01:02.902487+00 |                               | 2025-02-16 17:16:33.617858+00 | 2025-02-16 17:16:33.617875+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_0000209b                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 142 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 16:02:25.208052+00 |                               | 2025-02-16 17:16:33.646449+00 | 2025-02-16 17:16:33.646462+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_00001e23                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 231 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 16:15:18.310248+00 |                               | 2025-02-16 17:16:20.491731+00 | 2025-02-16 17:16:20.491744+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_000019da                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 249 |            |    16384 | nominatim |                            |             |                 |          -1 | 2025-02-16 16:21:56.987964+00 |                               | 2025-02-16 16:21:57.053278+00 | 2025-02-16 16:21:57.075199+00 | Client          | ClientRead          | idle   |             |              |          | COMMIT                                                                                        
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 253 |            |    16384 | nominatim | osm2pgsql.middle.main/C1   |             |                 |          -1 | 2025-02-16 16:21:57.297905+00 | 2025-02-16 17:04:05.849981+00 | 2025-02-16 17:05:00.318051+00 | 2025-02-16 17:05:00.318053+00 |                 |                     | active |    21515079 |     21515079 |          |                                                                                               
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                 +| client backend
       |           |     |            |          |           |                            |             |                 |             |                               |                               |                               |                               |                 |                     |        |             |              |          | INSERT INTO osm2pgsql_changed_ways                                                            
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                 +| 
       |           |     |            |          |           |                            |             |                 |             |                               |                               |                               |                               |                 |                     |        |             |              |          |   SELECT w.id                                                                                 
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                 +| 
       |           |     |            |          |           |                            |             |                 |             |                               |                               |                               |                               |                 |                     |        |             |              |          |     FROM "public"."planet_osm_ways" w, osm2pgsql_changed_nodes n                              
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                 +| 
       |           |     |            |          |           |                            |             |                 |             |                               |                               |                               |                               |                 |                     |        |             |              |          |     WHERE w.nodes && ARRAY[n.id]                                                              
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                 +| 
       |           |     |            |          |           |                            |             |                 |             |                               |                               |                               |                               |                 |                     |        |             |              |          |                                                                                               
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | 
 16386 | nominatim | 255 |            |    16384 | nominatim | osm2pgsql.copy/C2          |             |                 |          -1 | 2025-02-16 16:21:57.318666+00 |                               | 2025-02-16 16:21:57.329322+00 | 2025-02-16 16:21:57.32935+00  | Client          | ClientRead          | idle   |             |              |          | SET enable_seqscan = off                                                                      
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 256 |            |    16384 | nominatim | osm2pgsql.middle.query/C3  |             |                 |          -1 | 2025-02-16 16:21:57.509632+00 |                               | 2025-02-16 16:21:57.526601+00 | 2025-02-16 16:21:57.526815+00 | Client          | ClientRead          | idle   |             |              |          | PREPARE get_rel(int8) AS  SELECT members, tags    FROM "public"."planet_osm_rels" WHERE id = $
1                                                                                                                                                                                                                                                                                                                                                                                                                                                                
                  | client backend
 16386 | nominatim | 257 |            |    16384 | nominatim | osm2pgsql.out.flex.main/C4 |             |                 |          -1 | 2025-02-16 16:21:57.528286+00 |                               | 2025-02-16 16:21:57.540646+00 | 2025-02-16 16:21:57.543175+00 | Client          | ClientRead          | idle   |             |              |          | DROP TABLE IF EXISTS "public"."place_tmp"                                                     
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
 16386 | nominatim | 259 |            |    16384 | nominatim | osm2pgsql.copy/C5          |             |                 |          -1 | 2025-02-16 16:21:57.540234+00 | 2025-02-16 17:09:55.730989+00 | 2025-02-16 17:09:55.730989+00 | 2025-02-16 17:09:55.73099+00  | Client          | ClientRead          | active |             |     21515079 |          | COPY "public"."place" ("osm_type","osm_id","class","type","admin_level","name","address","extr
atags","geometry") FROM STDIN                                                                                                                                                                                                                                                                                                                                                                                                                                    
                  | client backend
 16386 | nominatim | 297 |            |    16385 | www-data  |                            |             |                 |          -1 | 2025-02-16 16:38:24.66256+00  |                               | 2025-02-16 17:16:45.342883+00 | 2025-02-16 17:16:45.342896+00 | Client          | ClientRead          | idle   |             |              |          | DEALLOCATE pdo_stmt_00000c98                                                                  
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | client backend
       |           |  39 |            |          |           |                            |             |                 |             | 2025-02-16 15:58:27.7681+00   |                               |                               |                               | Activity        | BgWriterMain        |        |             |              |          |                                                                                               
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | background writer
       |           |  38 |            |          |           |                            |             |                 |             | 2025-02-16 15:58:27.766965+00 |                               |                               |                               | Activity        | CheckpointerMain    |        |             |              |          |                                                                                               
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | checkpointer
       |           |  40 |            |          |           |                            |             |                 |             | 2025-02-16 15:58:27.769451+00 |                               |                               |                               | Activity        | WalWriterMain       |        |             |              |          |                                                                                               
                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
                  | walwriter

[lonvia]

Updating a full year is never a good idea. For 2024 it is pretty much impossible because of the vandalism issues that occurred mid-year.

I suggest to wait for the Nominatim 5.0 port of the docker container and then do a reimport.

[stouch]

@leonardehrenfried Do you plan to release the 5.0 port in the next weeks ? Thanks a lot

[leonardehrenfried]

No I don't. Do you want to contribute the upgrade?

[stouch]

What would it need to make such this upgrade ? Many things gonna change in the image/container context ?

[leonardehrenfried]

I think I did the heavy lifting with 4.5 but you will have to find out. I would start with bumping the version and seeing if the tests still pass.