chesty / renderd-docker

containerised renderd
Apache License 2.0
0 stars 2 forks source link

renderd-docker-entrypoint.sh: DB-Error during updatedb does not reload same sequemcenumber #1

Closed ghost closed 3 years ago

ghost commented 3 years ago

Situation: During updatedb the database-server terminated the connection. This causes that - after an increating waittime - the next change.file is downloaded. As a results there are missing nodes/ways/... in the database for the changes of one day .

Expected behavior: Reload the same change file again when loading of t

Logoutput - currently I have 15 errors, so more or less nodes/ways/.. are missing for these 15 days..

2021-02-11T01:20:35.868624999Z DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 2021-02-11T01:20:35.868633726Z HINT: In a moment you should be able to reconnect to the database and repeat your command. 2021-02-11T01:20:35.868637422Z terminate called after throwing an instance of 'std::runtime_error' 2021-02-11T01:20:35.868640548Z what(): result COPY_END for planet_osm_nodes failed: server closed the connection unexpectedly 2021-02-11T01:20:35.868650477Z This probably means the server terminated abnormally 2021-02-11T01:20:35.868654145Z before or while processing the request. 2021-02-11T01:20:35.868657281Z 2021-02-11T01:20:35.868660447Z 2021-02-11T01:22:19.320069605Z Aborted (core dumped) 2021-02-11T01:22:19.382489648Z 2021-02-11 01:22:19+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: renderd-updatedb osm2pgsql error applying changes to database, exit 3 2021-02-11T01:22:22.004262141Z 2021-02-11 01:22:22+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: starting osm-config.sh 2021-02-11T01:22:22.019606407Z 2021-02-11 01:22:22+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: NPROCS=8 HOSTNAME=d5825b0689c4 HOME=/root OSM_PBF_URL=https://ftp.gwdg.de/pub/misc/openstreetmap/planet.openstreetmap.org/pbf/planet-latest.osm.pbf OSM_PBF_UPDATE_URL=https://ftp.gwdg.de/pub/misc/openstreetmap/planet.openstreetmap.org/replication/day/ OSM_OSRM=planet-latest.osrm DATA_DIR=/data OSRM_ALGORITHM=MLD OSM_PBF=planet-latest.osm.pbf PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin OSM2PGSQLCACHE=12000 POSTGRES_HOST=postgres POSTGRES_USER=postgres OSM_PBF_BASENAME=planet-latest POSTGRES_PORT=5432 PG_MAJOR=12 PWD=/ POSTGRES_DB=gis WFS_SLEEP=30 RENDERD_UPDATE_SLEEP=10800 2021-02-11T01:22:22.074792928Z 2021-02-11 01:22:22+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: starting 2021-02-11T01:22:22.088035200Z 2021-02-11 01:22:22+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: renderd-updatedb called 2021-02-11T01:22:22.088746740Z 2021-02-11 01:22:22+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: creating shapefiles dir 2021-02-11T01:22:27.126411730Z 2021-02-11 01:22:27+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: renderd-updatedb /data/renderd-updatedb.lock found, previous run didn't finish successfully, rerunning 2021-02-11T01:22:27.129083495Z 2021-02-11 01:22:27+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: renderd-updatedb has failed 15 times before, sleeping for 54000 seconds 2021-02-11T16:22:27.148167107Z 2021-02-11 16:22:27+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: checking for new change file and downloading 2021-02-11T16:22:27.704200306Z Feb 11, 2021 4:22:27 PM org.openstreetmap.osmosis.core.Osmosis run 2021-02-11T16:22:27.704232357Z INFO: Osmosis Version 0.47 2021-02-11T16:22:28.015749201Z Feb 11, 2021 4:22:28 PM org.openstreetmap.osmosis.core.Osmosis run 2021-02-11T16:22:28.015783086Z INFO: Preparing pipeline. 2021-02-11T16:22:28.033308928Z Feb 11, 2021 4:22:28 PM org.openstreetmap.osmosis.core.Osmosis run 2021-02-11T16:22:28.033359814Z INFO: Launching pipeline execution. 2021-02-11T16:22:28.037102991Z Feb 11, 2021 4:22:28 PM org.openstreetmap.osmosis.core.Osmosis run 2021-02-11T16:22:28.037174146Z INFO: Pipeline executing, waiting for completion. 2021-02-11T16:24:04.364706986Z Feb 11, 2021 4:24:04 PM org.openstreetmap.osmosis.core.Osmosis run 2021-02-11T16:24:04.364739898Z INFO: Pipeline complete. 2021-02-11T16:24:04.365152400Z Feb 11, 2021 4:24:04 PM org.openstreetmap.osmosis.core.Osmosis run 2021-02-11T16:24:04.365163942Z INFO: Total execution time: 96720 milliseconds. 2021-02-11T16:24:04.453021630Z 2021-02-11 16:24:04+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: processing sequence number 3062 2021-02-11T16:24:04.453050445Z 2021-02-11 16:24:04+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: updating database

chesty commented 3 years ago

Hi, thanks for your report.

/usr/local/bin/renderd-docker-entrypoint.sh: processing sequence number 3062

did it fail processing 3061? I see it failed about 15 times, on the first retry did it try processing 3061?

edit:

thinking about this some more.

it successfully downloaded 3061 there was an error while it was processing 3061 when it retried, since it already has 3061, it should just process it again, it shouldn't try downloading any new updates until 3061 has been processed.

Does that sound right?

ghost commented 3 years ago

I have the issue for several days. I attached the log. osm.log It looks the this ibehaviour s caused by the exit 3 in line 212 in renderd-docker-entrypoint.sh. This terminates the script which is then started again and loads the next change-file. It seems that there is the same issue with the exit in line 219. When this line is reached the data of the last change-file is missing in the OSM_PBF-file.

I think the same happens when the docker-container is stopped/Server rebooted/... while a an apply of a change-file is running.

chesty commented 3 years ago

thanks. I think I understand what's happening and I'm made some changes, I'm testing it now but it's not easy to test so it might take a few days.

What I changed is the change file gets deleted after it's successfully applied, if it errors and exits it doesn't get deleted. When the update container starts it checks for a change file, if it finds one it tries to process it again and will keep trying until it's successful.

renderd-docker-entrypoint.txt

chesty commented 3 years ago

I believe it's fixed but I haven't done extensive testing. I did find a problem with the patch above during testing which I fixed. I guess you'll either need to manually update your db to get it up to date or just reload with the latest full file. fell feel to reopen if it doesn't work for you.

ghost commented 3 years ago

In the log of renderd-updatdb I see 2021-02-20 08:12:58+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: renderd-updatedb has failed 20 times before, sleeping for 72000 seconds Terminated 2021-02-20 08:13:52+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: renderd-updatedb old change file found which would indicate a previous error and exit, reprocessing 3068 2021-02-20 08:13:52+UTC -- /usr/local/bin/renderd-docker-entrypoint.sh: renderd-updatedb updating database osm2pgsql version 1.2.1 (64 bit id space) Allocating memory for dense node cache

That looks fine (I terminated the sleep 7200 to speed it up), it's not downloading the next file anymore.This file will terminate in some hours with an error again, then I can see whether the same file is tried again..

Unfortunatelly nominatim-apache and nominatim-updatedb are not starting. Both containers stay in state "Restarting" In both logs I see 2021-02-20 09:10:13+UTC -- /usr/local/bin/nominatim-docker-entrypoint.sh: starting osm-config.sh 2021-02-20 09:10:13+UTC -- /usr/local/bin/nominatim-docker-entrypoint.sh: FLOCKER=/data/nominatim-docker-entrypoint.sh-nominatim-updatedb-postgres-5432-gis-postgres.lock NPROCS=8 HOSTNAME=765b7647018c HOME=/root SUBCOMMAND=nominatim-updatedb OSM_PBF_URL=https://ftp.gwdg.de/pub/misc/openstreetmap/planet.openstreetmap.org/pbf/planet-latest.osm.pbf OSM_PBF_UPDATE_URL=https://ftp.gwdg.de/pub/misc/openstreetmap/planet.openstreetmap.org/replication/day/ OSM_OSRM=planet-latest.osrm DATA_DIR=/data OSRM_ALGORITHM=MLD OSM_PBF=planet-latest.osm.pbf PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/lib/postgresql/12/bin OSM2PGSQLCACHE=12000 POSTGRES_HOST=postgres POSTGRES_USER=postgres LANG=en_US.utf8 OSM_PBF_BASENAME=planet-latest POSTGRES_PORT=5432 PG_MAJOR=12 GOSU_VERSION=1.12 PWD=/Nominatim/build POSTGRES_DB=gis PGDATA=/var/lib/postgresql/data WFS_SLEEP=30 RENDERD_UPDATE_SLEEP=10800 BUMP=20200920.1 021-02-20 09:10:13+UTC -- /usr/local/bin/nominatim-docker-entrypoint.sh: starting nominatim-updatedb 2021-02-20 09:10:13+UTC -- /usr/local/bin/nominatim-docker-entrypoint.sh: nominatim-updatedb called PHP Warning: require(Symfony/Component/Dotenv/autoload.php): failed to open stream: No such file or directory in /Nominatim/lib-php/dotenv_loader.php on line 3 PHP Fatal error: require(): Failed opening required 'Symfony/Component/Dotenv/autoload.php' (include_path='.:/usr/share/php') in /Nominatim/lib-php/dotenv_loader.php on line 3

Looks like PHP-module dotenv is missing