search

omniscale / imposm3

Imposm imports OpenStreetMap data into PostGIS
http://imposm.org/docs/imposm3/latest/
Apache License 2.0
730 stars 157 forks source link

Bad deal with postgres error #229

Open frodrigo opened 4 years ago

frodrigo commented 4 years ago

Time to time I got this mixed output from imposm run. It comes from PostgreSQL error. It look like one import still running after an error on PostgreSQL. But next update start away way.

[Feb  7 09:02:54] [4h16m0s] C:       0/s       0/s (0) N:    3100/s       0/s (30422) W:     500/s       0/s (185811) 
[Feb  7 09:02:54] [11h4m42s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     600/s       0/s (185811)[Feb  7 09:02:55] [7h17m40s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     400/s       0/s (185811)
[Feb  7 09:02:55] [8h16m27s] C:       0/s       0/s (0) N:    2800/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [22m53s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811) R
[Feb  7 09:02:55] [3h13m33s] C:       0/s       0/s (0) N:    2800/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [2h17m14s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     600/s       0/s (185811)
[Feb  7 09:02:55] [10h11m43s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [1h22m6s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811) 
[Feb  7 09:02:55] [9h11m55s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [5h15m13s] C:       0/s       0/s (0) N:    2600/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [14h49m47s] C:       0/s       0/s (0) N:    3200/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [13h54m52s] C:       0/s       0/s (0) N:    2600/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [11h57m34s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [6h13m15s] C:       0/s       0/s (0) N:    2600/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [12h57m40s] C:       0/s       0/s (0) N:    3000/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [4h16m0s] C:       0/s       0/s (0) N:    3100/s       0/s (30422) W:     500/s       0/s (185811) 
[Feb  7 09:02:55] [11h4m43s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     600/s       0/s (185811)
[Feb  7 09:02:55] [7h17m41s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     400/s       0/s (185811)
[Feb  7 09:02:55] [8h16m28s] C:       0/s       0/s (0) N:    2800/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [22m53s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811) R
[Feb  7 09:02:55] [3h13m33s] C:       0/s       0/s (0) N:    2800/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [2h17m14s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     600/s       0/s (185811)
[Feb  7 09:02:55] [10h11m44s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [1h22m7s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811) 
[Feb  7 09:02:55] [9h11m56s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [5h15m13s] C:       0/s       0/s (0) N:    2600/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [14h49m47s] C:       0/s       0/s (0) N:    3200/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [13h54m52s] C:       0/s       0/s (0) N:    2600/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [11h57m34s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811
[Feb  7 09:02:55] [6h13m16s] C:       0/s       0/s (0) N:    2600/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:55] [12h57m40s] C:       0/s       0/s (0) N:    3000/s       0/s (30422) W:     500/s       0/s (185811[Feb  7 09:02:55] [4h16m1s] C:       0/s       0/s (0) N:    3100/s       0/s (30422) W:     500/s       0/s (185811) 
[Feb  7 09:02:55] [11h4m43s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     600/s       0/s (185811)
[Feb  7 09:02:56] [7h17m41s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     400/s       0/s (185811)
[Feb  7 09:02:56] [8h16m28s] C:       0/s       0/s (0) N:    2800/s       0/s (30422) W:     500/s       0/s (185811)
[Feb  7 09:02:56] [22m54s] C:       0/s       0/s (0) N:    2700/s       0/s (30422) W:     500/s       0/s (185811) R
[Feb  7 09:02:56] [3h13m34s] C:       0/s       0/s (0) N:    2800/s       0/s (30422) W:     500/s       0/s (185811) R
frodrigo commented 4 years ago

Failed process seem to be still here, doing some thing.

How to reproduce

imposm import \
    -config config.json \
    -mapping imposm.yaml \
    -read andorra-200325.osm.pbf \
    -overwritecache \
    -write \
    -diff \
    -cachedir ./cache \
    -diffdir ./diff \
    -connection postgis://fred@localhost/fred \
    -deployproduction

psql <<EOF
CREATE OR REPLACE FUNCTION osm_ways_fail() RETURNS trigger AS
  \$BODY\$
  BEGIN
    RAISE 'Planned fail.';
  END;
  \$BODY\$
language plpgsql;

CREATE CONSTRAINT TRIGGER osm_ways_fail
    AFTER INSERT ON osm_ways
    INITIALLY DEFERRED
    FOR EACH ROW
    EXECUTE PROCEDURE osm_ways_fail();
EOF

imposm run \
    -config config.json \
    -mapping imposm.yaml \
    -cachedir ./cache \
    -diffdir ./diff \
    -connection postgis://fred@localhost/fred

Log

$ imposm run     -config config.json     -mapping imposm.yaml     -cachedir ./cache     -diffdir ./diff     -connection postgis://fred@localhost/fred
[Mar 30 15:06:08] [INFO] Replication URL: http://download.geofabrik.de/europe/andorra-updates/
[Mar 30 15:06:08] [INFO] Replication interval: 24h0m0s
[Mar 30 15:06:08] [INFO] [replication] Processing sequence 2561
[Mar 30 15:06:08] [INFO] [replication] Downloading diff file from http://download.geofabrik.de/europe/andorra-updates/000/002/561.state.txt
[Mar 30 15:06:08] [INFO] [replication] Downloading diff file from http://download.geofabrik.de/europe/andorra-updates/000/002/561.osc.gz
[Mar 30 15:06:08] [INFO] [replication] Processing sequence 2562
[Mar 30 15:06:08] [INFO] [replication] Downloading diff file from http://download.geofabrik.de/europe/andorra-updates/000/002/562.state.txt
[Mar 30 15:06:08] [INFO] [replication] Downloading diff file from http://download.geofabrik.de/europe/andorra-updates/000/002/562.osc.gz
[Mar 30 15:06:08] [INFO] [replication] Processing sequence 2563
[Mar 30 15:06:08] [INFO] [replication] Downloading diff file from http://download.geofabrik.de/europe/andorra-updates/000/002/563.state.txt
[Mar 30 15:06:08] [INFO] [replication] Downloading diff file from http://download.geofabrik.de/europe/andorra-updates/000/002/563.osc.gz
[Mar 30 15:06:08] [INFO] [diff] Parsing changes, updating cache and removing elements took: 11.703351ms
[Mar 30 15:06:08] [INFO] [    0s] C:       0/s (9) N:       0/s (0) W:       0/s (4) R:      0/s (2)
[Mar 30 15:06:08] [INFO] [PostGIS] Updating generalized tables took: 21.405µs
[Mar 30 15:06:08] [INFO] [diff] Processing diff/000/002/561.osc.gz took: 35.833687ms
[Mar 30 15:06:08] [INFO] importing #2561 till 2020-03-25 21:59:02 +0000 UTC took: 36.671743ms
[Mar 30 15:06:08] [ERR] pq: Planned fail.
[Mar 30 15:06:08] [INFO] retrying in 2s
[Mar 30 15:06:09] [    0s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:09] [    1s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:10] [    1s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:10] [    2s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:10] [INFO] [diff] Parsing changes, updating cache and removing elements took: 35.130978ms
[Mar 30 15:06:10] [INFO] [    0s] C:       0/s (9) N:       0/s (0) W:       0/s (4) R:      0/s (2)
[Mar 30 15:06:10] [INFO] [PostGIS] Updating generalized tables took: 29.131µs
[Mar 30 15:06:10] [INFO] [diff] Processing diff/000/002/561.osc.gz took: 64.545926ms
[Mar 30 15:06:10] [INFO] importing #2561 till 2020-03-25 21:59:02 +0000 UTC took: 64.754092ms
[Mar 30 15:06:10] [ERR] pq: Planned fail.
[Mar 30 15:06:10] [INFO] retrying in 4s
[Mar 30 15:06:11] [    2s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:11] [    0s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:11] [    3s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:11] [    1s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:12] [    3s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:12] [    1s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:12] [    4s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:12] [    2s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:13] [    4s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:13] [    2s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:13] [    5s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:13] [    3s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:14] [    5s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:14] [    3s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:14] [    6s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:14] [    4s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:14] [INFO] [diff] Parsing changes, updating cache and removing elements took: 25.761932ms
[Mar 30 15:06:14] [INFO] [    0s] C:       0/s (9) N:       0/s (0) W:       0/s (4) R:      0/s (2)
[Mar 30 15:06:14] [INFO] [PostGIS] Updating generalized tables took: 29.399µs
[Mar 30 15:06:14] [INFO] [diff] Processing diff/000/002/561.osc.gz took: 50.465934ms
[Mar 30 15:06:14] [INFO] importing #2561 till 2020-03-25 21:59:02 +0000 UTC took: 50.843773ms
[Mar 30 15:06:14] [ERR] pq: Planned fail.
[Mar 30 15:06:14] [INFO] retrying in 8s
[Mar 30 15:06:15] [    6s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:15] [    4s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:15] [    0s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:15] [    7s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:15] [    5s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:15] [    1s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:16] [    7s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:16] [    5s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:16] [    1s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:16] [    8s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
^C[Mar 30 15:06:16] [    6s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      
[Mar 30 15:06:16] [    2s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:17] [    8s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:17] [    6s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:17] [    2s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:17] [    9s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:17] [    7s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:17] [    3s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:18] [    9s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:18] [    7s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:18] [    3s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:18] [   10s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:18] [    8s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:18] [    4s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:19] [   10s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:19] [    8s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:19] [    4s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:19] [   11s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:19] [    9s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:19] [    5s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:20] [   11s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:20] [    9s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:20] [    5s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:20] [   12s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:20] [   10s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:20] [    6s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:21] [   12s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:21] [   10s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:21] [    6s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:21] [   13s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:21] [   11s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:21] [    7s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:22] [   13s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:22] [   11s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:22] [    7s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:22] [   14s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:22] [   12s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:22] [    8s] C:       0/s       0/s (0) N:       0/s       0/s (8) W:       0/s       0/s (5) R:      0/
[Mar 30 15:06:22] [INFO] [diff] Parsing changes, updating cache and removing elements took: 19.19232ms
[Mar 30 15:06:22] [INFO] [    0s] C:       0/s (9) N:       0/s (0) W:       0/s (4) R:      0/s (2)
[Mar 30 15:06:22] [INFO] [PostGIS] Updating generalized tables took: 22.518µs
[Mar 30 15:06:22] [INFO] [diff] Processing diff/000/002/561.osc.gz took: 40.564471ms
[Mar 30 15:06:22] [INFO] importing #2561 till 2020-03-25 21:59:02 +0000 UTC took: 41.298764ms
[Mar 30 15:06:22] [INFO] Exiting. (SIGTERM/SIGINT/SIGHUB)
frodrigo commented 4 years ago

Issue seem solved with version 0.10. I need to confirm.

frodrigo commented 4 years ago

No. Issue is still here, but not visible when you play with puppet data. Update have to be longer than a minute now to see the duplicate lines.