Skip to content

Commit c867a59

Browse files
apmonapmon
committed
[osm2pgsql] Report some more timing information to see where osm2pgsql spends its time
1 parent 5d5b396 commit c867a59

6 files changed

Lines changed: 86 additions & 15 deletions

File tree

‎middle-pgsql.c‎

Lines changed: 21 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@
1414
#include <string.h>
1515
#include <assert.h>
1616
#include <math.h>
17+
#include <time.h>
1718

1819
#ifdef HAVE_PTHREAD
1920
#include <pthread.h>
@@ -913,6 +914,8 @@ static void pgsql_iterate_ways(int (*callback)(osmid_t id, struct keyval *tags,
913914
/* The flag we pass to indicate that the way in question might exist already in the database */
914915
int exists = Append;
915916

917+
time_t start, end;
918+
time(&start);
916919
fprintf(stderr, "\nGoing over pending ways\n");
917920

918921
/* Make sure we're out of copy mode */
@@ -927,8 +930,11 @@ static void pgsql_iterate_ways(int (*callback)(osmid_t id, struct keyval *tags,
927930
struct osmNode *nodes;
928931
int nd_count;
929932

930-
if (count++ %1000 == 0)
931-
fprintf(stderr, "\rprocessing way (%dk)", count/1000);
933+
if (count++ %1000 == 0) {
934+
time(&end);
935+
fprintf(stderr, "\rprocessing way (%dk) at %.2fk/s", count/1000,
936+
(int)(end - start) > 0 ? ((double)count / 1000.0 / (double)(end - start)) : 0);
937+
}
932938

933939
initList(&tags);
934940
if( pgsql_ways_get(id, &tags, &nodes, &nd_count) )
@@ -943,6 +949,9 @@ static void pgsql_iterate_ways(int (*callback)(osmid_t id, struct keyval *tags,
943949

944950
PQclear(res_ways);
945951
fprintf(stderr, "\n");
952+
time(&end);
953+
if (end - start > 0)
954+
fprintf(stderr, "Pending ways took %ds at a rate of %.2f/s\n",(int)(end - start), ((double)count / (double)(end - start)));
946955
}
947956

948957
static int pgsql_way_changed(osmid_t osm_id)
@@ -1112,6 +1121,8 @@ static void pgsql_iterate_relations(int (*callback)(osmid_t id, struct member *m
11121121
/* The flag we pass to indicate that the way in question might exist already in the database */
11131122
int exists = Append;
11141123

1124+
time_t start, end;
1125+
time(&start);
11151126
fprintf(stderr, "\nGoing over pending relations\n");
11161127

11171128
/* Make sure we're out of copy mode */
@@ -1126,8 +1137,11 @@ static void pgsql_iterate_relations(int (*callback)(osmid_t id, struct member *m
11261137
struct member *members;
11271138
int member_count;
11281139

1129-
if (count++ %10 == 0)
1130-
fprintf(stderr, "\rprocessing relation (%d)", count);
1140+
if (count++ %10 == 0) {
1141+
time(&end);
1142+
fprintf(stderr, "\rprocessing relation (%d) at %.2f/s", count,
1143+
(int)(end - start) > 0 ? ((double)count / (double)(end - start)) : 0);
1144+
}
11311145

11321146
initList(&tags);
11331147
if( pgsql_rels_get(id, &members, &member_count, &tags) )
@@ -1142,6 +1156,9 @@ static void pgsql_iterate_relations(int (*callback)(osmid_t id, struct member *m
11421156

11431157
PQclear(res_rels);
11441158
fprintf(stderr, "\n");
1159+
time(&end);
1160+
if (end - start > 0)
1161+
fprintf(stderr, "Pending relations took %ds at a rate of %.2f/s\n",(int)(end - start), ((double)count / (double)(end - start)));
11451162
}
11461163

11471164
static int pgsql_rel_changed(osmid_t osm_id)

‎osm2pgsql.c‎

Lines changed: 30 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -281,8 +281,20 @@ void resetMembers(struct osmdata_t *osmdata)
281281

282282
void printStatus(struct osmdata_t *osmdata)
283283
{
284-
fprintf(stderr, "\rProcessing: Node(%" PRIdOSMID "k) Way(%" PRIdOSMID "k) Relation(%" PRIdOSMID ")",
285-
osmdata->count_node/1000, osmdata->count_way/1000, osmdata->count_rel);
284+
time_t now;
285+
time(&now);
286+
time_t end_nodes = osmdata->start_way > 0 ? osmdata->start_way : now;
287+
time_t end_way = osmdata->start_rel > 0 ? osmdata->start_rel : now;
288+
time_t end_rel = now;
289+
fprintf(stderr, "\rProcessing: Node(%" PRIdOSMID "k %.1fk/s) Way(%" PRIdOSMID "k %.2fk/s) Relation(%" PRIdOSMID " %.2f/s)",
290+
osmdata->count_node/1000,
291+
(double)osmdata->count_node/1000.0/((int)(end_nodes - osmdata->start_node) > 0 ? (double)(end_nodes - osmdata->start_node) : 1.0),
292+
osmdata->count_way/1000,
293+
osmdata->count_way > 0 ? (double)osmdata->count_way/1000.0/
294+
((double)(end_way - osmdata->start_way) > 0.0 ? (double)(end_way - osmdata->start_way) : 1.0) : 0.0,
295+
osmdata->count_rel,
296+
osmdata->count_rel > 0 ? (double)osmdata->count_rel/
297+
((double)(end_rel - osmdata->start_rel) > 0.0 ? (double)(end_rel - osmdata->start_rel) : 1.0) : 0.0);
286298
}
287299

288300
int node_wanted(struct osmdata_t *osmdata, double lat, double lon)
@@ -534,6 +546,9 @@ int main(int argc, char *argv[])
534546
}
535547
}
536548

549+
time_t overall_start, overall_end;
550+
time(&overall_start);
551+
537552
osmdata.out->start(&options);
538553

539554
realloc_nodes(&osmdata);
@@ -575,10 +590,18 @@ int main(int argc, char *argv[])
575590
xmlMemoryDump();
576591

577592
if (osmdata.count_node || osmdata.count_way || osmdata.count_rel) {
593+
time_t now;
594+
time(&now);
595+
time_t end_nodes = osmdata.start_way > 0 ? osmdata.start_way : now;
596+
time_t end_way = osmdata.start_rel > 0 ? osmdata.start_rel : now;
597+
time_t end_rel = now;
578598
fprintf(stderr, "\n");
579-
fprintf(stderr, "Node stats: total(%" PRIdOSMID "), max(%" PRIdOSMID ")\n", osmdata.count_node, osmdata.max_node);
580-
fprintf(stderr, "Way stats: total(%" PRIdOSMID "), max(%" PRIdOSMID ")\n", osmdata.count_way, osmdata.max_way);
581-
fprintf(stderr, "Relation stats: total(%" PRIdOSMID "), max(%" PRIdOSMID ")\n", osmdata.count_rel, osmdata.max_rel);
599+
fprintf(stderr, "Node stats: total(%" PRIdOSMID "), max(%" PRIdOSMID ") in %is\n", osmdata.count_node, osmdata.max_node,
600+
osmdata.count_node > 0 ? (int)(end_nodes - osmdata.start_node) : 0);
601+
fprintf(stderr, "Way stats: total(%" PRIdOSMID "), max(%" PRIdOSMID ") in %is\n", osmdata.count_way, osmdata.max_way,
602+
osmdata.count_way > 0 ? (int)(end_way - osmdata.start_way) : 0);
603+
fprintf(stderr, "Relation stats: total(%" PRIdOSMID "), max(%" PRIdOSMID ") in %is\n", osmdata.count_rel, osmdata.max_rel,
604+
osmdata.count_rel > 0 ? (int)(end_rel - osmdata.start_rel) : 0);
582605
}
583606
osmdata.out->stop();
584607

@@ -591,6 +614,8 @@ int main(int argc, char *argv[])
591614
project_exit();
592615
text_exit();
593616
fprintf(stderr, "\n");
617+
time(&overall_end);
618+
fprintf(stderr, "Osm2pgsql took %ds overall\n", (int)(overall_end - overall_start));
594619

595620
return 0;
596621
}

‎osmtypes.h‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,7 @@ struct osmdata_t {
4242
osmid_t count_node, max_node;
4343
osmid_t count_way, max_way;
4444
osmid_t count_rel, max_rel;
45+
time_t start_node, start_way, start_rel;
4546

4647
struct output_t *out;
4748

‎output-pgsql.c‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@
1414
#include <string.h>
1515
#include <assert.h>
1616
#include <errno.h>
17+
#include <time.h>
1718

1819
#ifdef HAVE_PTHREAD
1920
#include <pthread.h>
@@ -1359,6 +1360,8 @@ static void *pgsql_out_stop_one(void *arg)
13591360
pgsql_exec(sql_conn, PGRES_COMMAND_OK, "COMMIT");
13601361
if (!Options->append)
13611362
{
1363+
time_t start, end;
1364+
time(&start);
13621365
fprintf(stderr, "Sorting data and creating indexes for %s\n", table->name);
13631366
pgsql_exec(sql_conn, PGRES_COMMAND_OK, "ANALYZE %s;\n", table->name);
13641367
pgsql_exec(sql_conn, PGRES_COMMAND_OK, "CREATE TABLE %s_tmp AS SELECT * FROM %s ORDER BY way;\n", table->name, table->name);
@@ -1381,9 +1384,12 @@ static void *pgsql_out_stop_one(void *arg)
13811384
}
13821385
pgsql_exec(sql_conn, PGRES_COMMAND_OK, "GRANT SELECT ON %s TO PUBLIC;\n", table->name);
13831386
pgsql_exec(sql_conn, PGRES_COMMAND_OK, "ANALYZE %s;\n", table->name);
1387+
time(&end);
1388+
fprintf(stderr, "Indexes on %s created in %ds\n", table->name, (int)(end - start));
13841389
}
13851390
PQfinish(sql_conn);
13861391
table->sql_conn = NULL;
1392+
13871393
fprintf(stderr, "Completed %s\n", table->name);
13881394
free(table->name);
13891395
free(table->columns);
@@ -1498,7 +1504,6 @@ static int pgsql_process_relation(osmid_t id, struct member *members, int member
14981504
xcount[count] = 0;
14991505
xid[count] = 0;
15001506
xrole[count] = NULL;
1501-
15021507
// At some point we might want to consider storing the retreived data in the members, rather than as seperate arrays
15031508
pgsql_out_relation(id, tags, xnodes, xtags, xcount, xid, xrole);
15041509

‎parse-pbf.c‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@
2626
#include <stdio.h>
2727
#include <string.h>
2828
#include <arpa/inet.h>
29+
#include <time.h>
2930

3031
#include <zlib.h>
3132
#include <bzlib.h>
@@ -283,6 +284,9 @@ int processOsmDataNodes(struct osmdata_t *osmdata, PrimitiveGroup *group, String
283284
osmdata->max_node = node->id;
284285
}
285286

287+
if (osmdata->count_node == 0) {
288+
time(&osmdata->start_node);
289+
}
286290
osmdata->count_node++;
287291
if (osmdata->count_node%10000 == 0)
288292
printStatus(osmdata);
@@ -357,6 +361,9 @@ int processOsmDataDenseNodes(struct osmdata_t *osmdata, PrimitiveGroup *group, S
357361
osmdata->max_node = deltaid;
358362
}
359363

364+
if (osmdata->count_node == 0) {
365+
time(&osmdata->start_node);
366+
}
360367
osmdata->count_node++;
361368
if (osmdata->count_node%10000 == 0)
362369
printStatus(osmdata);
@@ -405,6 +412,9 @@ int processOsmDataWays(struct osmdata_t *osmdata, PrimitiveGroup *group, StringT
405412
osmdata->max_way = way->id;
406413
}
407414

415+
if (osmdata->count_way == 0) {
416+
time(&osmdata->start_way);
417+
}
408418
osmdata->count_way++;
409419
if (osmdata->count_way%1000 == 0)
410420
printStatus(osmdata);
@@ -481,6 +491,9 @@ int processOsmDataRelations(struct osmdata_t *osmdata, PrimitiveGroup *group, St
481491
osmdata->max_rel = relation->id;
482492
}
483493

494+
if (osmdata->count_rel == 0) {
495+
time(&osmdata->start_rel);
496+
}
484497
osmdata->count_rel++;
485498
if (osmdata->count_rel%10 == 0)
486499
printStatus(osmdata);

‎parse-xml2.c‎

Lines changed: 15 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@
2828
#include <stdlib.h>
2929
#include <string.h>
3030
#include <assert.h>
31+
#include <time.h>
3132

3233
#include <libxml/xmlstring.h>
3334
#include <libxml/xmlreader.h>
@@ -107,6 +108,9 @@ static void StartElement(xmlTextReaderPtr reader, const xmlChar *name, struct os
107108
if (osmdata->osm_id > osmdata->max_node)
108109
osmdata->max_node = osmdata->osm_id;
109110

111+
if (osmdata->count_node == 0) {
112+
time(&osmdata->start_node);
113+
}
110114
osmdata->count_node++;
111115
if (osmdata->count_node%10000 == 0)
112116
printStatus(osmdata);
@@ -138,14 +142,17 @@ static void StartElement(xmlTextReaderPtr reader, const xmlChar *name, struct os
138142
assert(xid);
139143
osmdata->osm_id = strtoosmid((char *)xid, NULL, 10);
140144
osmdata->action = ParseAction( reader, osmdata );
141-
145+
142146
if (osmdata->osm_id > osmdata->max_way)
143-
osmdata->max_way = osmdata->osm_id;
144-
147+
osmdata->max_way = osmdata->osm_id;
148+
149+
if (osmdata->count_way == 0) {
150+
time(&osmdata->start_way);
151+
}
145152
osmdata->count_way++;
146153
if (osmdata->count_way%1000 == 0)
147-
printStatus(osmdata);
148-
154+
printStatus(osmdata);
155+
149156
osmdata->nd_count = 0;
150157
xmlFree(xid);
151158

@@ -167,6 +174,9 @@ static void StartElement(xmlTextReaderPtr reader, const xmlChar *name, struct os
167174
if (osmdata->osm_id > osmdata->max_rel)
168175
osmdata->max_rel = osmdata->osm_id;
169176

177+
if (osmdata->count_rel == 0) {
178+
time(&osmdata->start_rel);
179+
}
170180
osmdata->count_rel++;
171181
if (osmdata->count_rel%10 == 0)
172182
printStatus(osmdata);

0 commit comments

Comments
 (0)