[GraphHopper] Jetty stops after starting

Sat May 30 06:54:30 UTC 2015

I have a simple cron script for updating gh graph:

wget "$LATEST_PBF" -O "$GH_PBF_FILE"
rm -rf "$GH_GRAPH_PATH"
service jetty8 restart

After last step of this script (Jetty restarting) Jetty starts and run
process of graph creation.
But after couple of minute I try to check Jetty status and get:

 * Jetty servlet engine is not running, but pid file exists.

graph.location directory also emty (contains only lock file). Log file
shows that graph creation is interrupted:

2015-05-29 10:00:34.284:INFO:oejs.Server:Graceful shutdown
> SelectChannelConnector at 0.0.0.0:8080
> 2015-05-29 10:00:34.288:INFO:oejs.Server:Graceful shutdown
> o.e.j.w.WebAppContext{,file:/var/lib/jetty8/webapps/root/},file:/var/lib/jetty8/webapps/root/
> 2015-05-29 10:00:34.288:INFO:oejs.Server:Graceful shutdown
> o.e.j.w.WebAppContext{/graphhopper-web-0.4-SNAPSHOT,file:/var/cache/jetty8/data/jetty-0.0.0.0-8080-graphhopper-web-0.4-SNAPSHOT.war-_graphhopper-web-0.4-SNAPSHOT-any-/webapp/},file:/var/lib/jetty8/webapps/graphhopper-web-0.4-SNAPSHOT.war
> 2015-05-29 10:00:35.320:INFO:oejsh.ContextHandler:stopped
> o.e.j.w.WebAppContext{/graphhopper-web-0.4-SNAPSHOT,file:/var/cache/jetty8/data/jetty-0.0.0.0-8080-graphhopper-web-0.4-SNAPSHOT.war-_graphhopper-web-0.4-SNAPSHOT-any-/webapp/},file:/var/lib/jetty8/webapps/graphhopper-web-0.4-SNAPSHOT.war
> 2015-05-29 10:00:35.326:INFO:oejsh.ContextHandler:stopped
> o.e.j.w.WebAppContext{,file:/var/lib/jetty8/webapps/root/},file:/var/lib/jetty8/webapps/root/
> 2015-05-29 10:00:38.198:WARN:oejd.WebAppDeployer:WebAppDeployer is
> deprecated. Use WebAppProvider
> 2015-05-29 10:00:38.199:INFO:oejs.Server:jetty-8.1.3.v20120416
> 2015-05-29 10:00:38.336:INFO:oejw.StandardDescriptorProcessor:NO JSP
> Support for , did not find org.apache.jasper.servlet.JspServlet
> 2015-05-29 10:00:38.387:INFO:oejsh.ContextHandler:started
> o.e.j.w.WebAppContext{,file:/var/lib/jetty8/webapps/root/},file:/var/lib/jetty8/webapps/root/
> 2015-05-29 10:00:38.387:INFO:oejsh.ContextHandler:started
> o.e.j.w.WebAppContext{,file:/var/lib/jetty8/webapps/root/},file:/var/lib/jetty8/webapps/root/
> 2015-05-29 10:00:38.400:INFO:oejw.WebInfConfiguration:Extract
> jar:file:/var/lib/jetty8/webapps/graphhopper-web-0.4-SNAPSHOT.war!/ to
> /var/cache/jetty8/data/jetty-0.0.0.0-8080-graphhopper-web-0.4-SNAPSHOT.war-_graphhopper-web-0.4-SNAPSHOT-any-/webapp
> 2015-05-29 10:00:39.284:INFO:oejw.StandardDescriptorProcessor:NO JSP
> Support for /graphhopper-web-0.4-SNAPSHOT, did not find
> org.apache.jasper.servlet.JspServlet
> 2015-05-29 10:00:39.366:INFO:oejsh.ContextHandler:started
> o.e.j.w.WebAppContext{/graphhopper-web-0.4-SNAPSHOT,file:/var/cache/jetty8/data/jetty-0.0.0.0-8080-graphhopper-web-0.4-SNAPSHOT.war-_graphhopper-web-0.4-SNAPSHOT-any-/webapp/},file:/var/lib/jetty8/webapps/graphhopper-web-0.4-SNAPSHOT.war
> 2015-05-29 10:00:39.367:INFO:oejsh.ContextHandler:started
> o.e.j.w.WebAppContext{/graphhopper-web-0.4-SNAPSHOT,file:/var/cache/jetty8/data/jetty-0.0.0.0-8080-graphhopper-web-0.4-SNAPSHOT.war-_graphhopper-web-0.4-SNAPSHOT-any-/webapp/},file:/var/lib/jetty8/webapps/graphhopper-web-0.4-SNAPSHOT.war
> 2015-05-29 10:00:39,563 [main] INFO  com.graphhopper.GraphHopper - version
> 0.4|2015-01-12T12:08:48+0300 (3,9,3,2,2)
> 2015-05-29 10:00:39,567 [main] INFO  com.graphhopper.GraphHopper - graph
> LevelGraphStorage|foot|RAM_STORE|2D|NoExt|,,,,, details:edges:0(0),
> nodes:0(0), name: /(0), geo:0(0),
> bounds:1.7976931348623157E308,-1.7976931348623157E308,1.7976931348623157E308,-1.7976931348623157E308
> 2015-05-29 10:00:39,585 [main] INFO  com.graphhopper.GraphHopper - start
> creating graph from /home/dr/graphhopper/data/RU-MOS.osm.pbf
> 2015-05-29 10:00:39,586 [main] INFO  com.graphhopper.GraphHopper - using
> LevelGraphStorage|foot|RAM_STORE|2D|NoExt|,,,,, memory:totalMB:38, usedMB:17
> 2015-05-29 10:01:36,052 [main] INFO  com.graphhopper.reader.OSMReader - 50
> 000 (preprocess), osmWayMap:8 totalMB:246, usedMB:152
> 2015-05-29 10:01:36,457 [main] INFO  com.graphhopper.reader.OSMReader -
> creating graph. Found nodes (pillar+tower):2 323 676, totalMB:246, usedMB:96
> 2015-05-29 10:01:59,742 [main] INFO  com.graphhopper.reader.OSMReader - 11
> 129 757, now parsing ways
> 2015-05-29 10:02:27,477 [main] INFO  com.graphhopper.reader.OSMReader - 12
> 640 549, now parsing relations
> 2015-05-29 10:02:27,559 [main] INFO  com.graphhopper.reader.OSMReader -
> finished way processing. nodes: 717337, osmIdMap.size:2326244,
> osmIdMap:32MB, nodeFlagsMap.size:2568, relFlagsMap.size:11 totalMB:354,
> usedMB:291
> 2015-05-29 10:02:27,576 [main] INFO  com.graphhopper.reader.OSMReader -
> time(pass1): 56 pass2: 51 total:107
> 2015-05-29 10:02:27,578 [main] INFO  com.graphhopper.GraphHopper - start
> finding subnetworks, totalMB:354, usedMB:291
> 2015-05-29 10:02:28,475 [main] INFO
>  com.graphhopper.routing.util.PrepareRoutingSubnetworks - optimize to
> remove subnetworks (5413), zero-degree-nodes (0),
> unvisited-dead-end-nodes(0), maxEdges/node (8)
> 2015-05-29 10:02:29,848 [main] INFO  com.graphhopper.GraphHopper - edges:
> 956287, nodes 700118, there were 5413 subnetworks. removed them => 17219
> less nodes. Remaining subnetworks:2
> 2015-05-29 10:02:29,848 [main] INFO  com.graphhopper.GraphHopper -
> optimizing ... (totalMB:347, usedMB:181)
> 2015-05-29 10:02:29,849 [main] INFO  com.graphhopper.GraphHopper -
> finished optimize (totalMB:347, usedMB:181)
> 2015-05-29 10:02:29,855 [main] INFO  com.graphhopper.GraphHopper - calling
> prepare.doWork for foot ... (totalMB:347, usedMB:182)
> 2015-05-29 10:02:35,402 [main] INFO
>  com.graphhopper.routing.ch.PrepareContractionHierarchies - 0, updates:0,
> nodes: 700 118, shortcuts:0, dijkstras:3 749 152, t(dijk):2, t(period):0,
> t(lazy):0, t(neighbor):0, meanDegree:1, algo:10MB, totalMB:347, usedMB:242
> 2015-05-29 10:02:37,229 [main] INFO
>  com.graphhopper.routing.ch.PrepareContractionHierarchies - 140 020,
> updates:0, nodes: 560 098, shortcuts:5 520, dijkstras:3 846 398, t(dijk):0,
> t(period):0, t(lazy):0, t(neighbor):1, meanDegree:1, algo:10MB,
> totalMB:347, usedMB:252
> 2015-05-29 10:03:01,446 [main] INFO
>  com.graphhopper.routing.ch.PrepareContractionHierarchies - 280 040,
> updates:1, nodes: 420 078, shortcuts:93 870, dijkstras:7 594 725,
> t(dijk):20, t(period):20, t(lazy):0, t(neighbor):1, meanDegree:1,
> algo:10MB, totalMB:348, usedMB:260
> 2015-05-29 10:03:24,852 [main] INFO
>  com.graphhopper.routing.ch.PrepareContractionHierarchies - 420 060,
> updates:2, nodes: 280 058, shortcuts:226 007, dijkstras:10 731 996,
> t(dijk):19, t(period):17, t(lazy):0, t(neighbor):2, meanDegree:3,
> algo:10MB, totalMB:347, usedMB:240

For fix this problem I have to restart Jetty manually. Sometimes I have to
restart it multiple times because after first restarting I get the same
problem as described above.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstreetmap.org/pipermail/graphhopper/attachments/20150530/a13f6ef0/attachment.html>