[mkgmap-dev] Mkgmap appears to hang on some split files

Mon Sep 28 16:58:48 BST 2009

have seen frequent java crashes when I run more than one mkmap in  
parallel. Even when the machine has 4 cores and plenty of memory.
it happens for openJDK and sun java.
when I run ~400 tiles for north america it runs without crash, 2  
parallel jobs are ok most of the time but 3 jobs is too much and java  
crashes about every 50th tile

On 28 Sep 2009, at 8:38 , Lambertus wrote:

> The box is a laptop with a single Intel P8600 CPU (dual core Penryn)  
> and when the process hangs it's just 1 core that is at 100% (I use  
> only one core so I can render America and Eurasia in parallel).
>
> I've tried the --max-jobs=1 parameter a few times and got it to  
> hang, stackdump (which seems identical to the earlier one I posted)  
> is attached. Funny thing is that the process produces a stackdump  
> with kill -3 <pid> but it continues to run at 100%. Kill -4 is  
> needed to persuade it to really stop.
>
>
>
> Chris Miller wrote:
>> Ah ok that makes more sense. A crash dump usually indicates the VM  
>> has a bug or has died 'violently' (as is the case here). A stack  
>> dump on the other hand is produced by the VM and shows you what  
>> Java code is currently executing.
>> It looks like you are running on a dual CPU box (two dual-core  
>> Xeons?). Are you also saying that you only hit the problem  
>> sometimes; you can rerun the same command again and it will run to  
>> completion just fine? Also, you say mkgmap is hung at 100% CPU. Is  
>> that all 4 cores, or just one of them?
>> One thing dual CPU boxes can be good at is highlighting otherwise  
>> obscure multithreaded bugs. I'm not familiar with the threading in  
>> mkgmap but possibly you're hitting a race condition in the code (eg  
>> an unsynchronized HashMap can behave like this). I've just had a  
>> quick glance at the code however and can't see anything obvious -  
>> there's very little shared state and what little there is appears  
>> to be synchronized OK. Which makes me wonder if, as Steve points  
>> out, the problem lies with your VM rather than mkgmap. Definitely  
>> worth trying another (or newer version of the existing) VM.
>> Thanks for getting a stack dump. It's interesting, mkgmap is inside  
>> native array-copying code while parsing an osm file. There's only  
>> one worker thread running at this point, I'm surprised to see it  
>> hanging there. Can you try running with --max-jobs=1 to see if the  
>> problem still happens?
>> Chris
>> L> Thanks Steve, Chris,
>> L> L> The error files were produced using kill -4 <pid>. Kill -1  
>> till -3
>> L> had no effect on the process. Just switching to using Sun Java is
>> L> probably the easy way out, but I reckon it's interesting to find  
>> out
>> L> what happened :-), so next time I'll try jstack before killing the
>> L> process.
>> L> L> Sorry that the VM crash dumps aren't useful.
>> L> L> Steve Ratcliffe wrote:
>> L>
>>>> On 28/09/09 13:53, Lambertus wrote:
>>>>
>>>>> It happened again, this time straight from the commandline while
>>>>> trying to render the three failed tiles at once by providing r2228
>>>>> the *.osm.gz parameter... Stack dump is attached.
>>>>>
>>>> Those hs_err_* files were not what I was expecting at all.  You
>>>> normally get one of those when the java process itself crashes and
>>>> that is always a bug in java and not the application.  How exactly
>>>> did you provoke it into dropping that file?
>>>>
>>>> I see from them that you are using the openjdk with Ubuntu,
>>>> so I tried openjdk on my Fedora machine and didn't get a problem  
>>>> but
>>>> then it is 32bit and has a higher build number so probably has
>>>> different (perhaps fewer ;) bugs.
>>>> If you can I'd try the Sun jdk instead to see if that is any
>>>> different.
>>>>
>>>> ..Steve
>> _______________________________________________
>> mkgmap-dev mailing list
>> mkgmap-dev at lists.mkgmap.org.uk
>> http://www.mkgmap.org.uk/mailman/listinfo/mkgmap-dev
>
> java -Xmx1792M -ea -jar ~/garmin/utils/mkgmap-r1228/mkgmap.jar -- 
> latin1 --code-page=1252 --name-tag-list=name:en,int_name,name -- 
> remove-short-arcs --add-pois-to-areas --make-opposite-cycleways -- 
> link-pois-to-ways --description='OSM World Routable' --route -- 
> series-name='OSM World Routable' --max-jobs=1 *.osm.gz
> 2009-09-28 17:33:19
> Full thread dump OpenJDK 64-Bit Server VM (14.0-b08 mixed mode):
>
> "pool-1-thread-1" prio=10 tid=0x00007f783c05b800 nid=0x44c waiting  
> on condition [0x00007f783baf9000..0x00007f783baf9c70]
>   java.lang.Thread.State: RUNNABLE
> 	at java.util.Arrays.copyOfRange(Arrays.java:3221)
> 	at java.lang.String.<init>(String.java:233)
> 	at com.sun.org.apache.xerces.internal.xni.XMLString.toString 
> (XMLString.java:188)
> 	at  
> com.sun.org.apache.xerces.internal.util.XMLAttributesImpl.getValue 
> (XMLAttributesImpl.java:540)
> 	at  
> com.sun.org.apache.xerces.internal.xinclude.XIncludeHandler.processAttributes 
> (XIncludeHandler.java:2033)
> 	at  
> com.sun.org.apache.xerces.internal.xinclude.XIncludeHandler.emptyElement 
> (XIncludeHandler.java:980)
> 	at  
> com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.scanStartElement 
> (XMLNSDocumentScannerImpl.java:353)
> 	at  
> com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl 
> $FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2723)
> 	at  
> com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next 
> (XMLDocumentScannerImpl.java:624)
> 	at  
> com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next 
> (XMLNSDocumentScannerImpl.java:116)
> 	at  
> com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument 
> (XMLDocumentFragmentScannerImpl.java:486)
> 	at  
> com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse 
> (XML11Configuration.java:810)
> 	at  
> com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse 
> (XML11Configuration.java:740)
> 	at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse 
> (XMLParser.java:110)
> 	at  
> com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse 
> (AbstractSAXParser.java:1208)
> 	at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl 
> $JAXPSAXParser.parse(SAXParserImpl.java:525)
> 	at javax.xml.parsers.SAXParser.parse(SAXParser.java:392)
> 	at javax.xml.parsers.SAXParser.parse(SAXParser.java:195)
> 	at uk.me.parabola.mkgmap.reader.osm.xml.Osm5MapDataSource.load 
> (Osm5MapDataSource.java:80)
> 	at uk.me.parabola.mkgmap.main.MapMaker.loadFromFile(MapMaker.java: 
> 148)
> 	- locked <0x00007f78411fd1e8> (a java.lang.Class for  
> uk.me.parabola.mkgmap.main.MapMaker)
> 	at uk.me.parabola.mkgmap.main.MapMaker.makeMap(MapMaker.java:56)
> 	at uk.me.parabola.mkgmap.main.Main$1.call(Main.java:186)
> 	at uk.me.parabola.mkgmap.main.Main$1.call(Main.java:184)
> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker 
> (ThreadPoolExecutor.java:1110)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run 
> (ThreadPoolExecutor.java:603)
> 	at java.lang.Thread.run(Thread.java:636)
>
> "Low Memory Detector" daemon prio=10 tid=0x00007f783c029000  
> nid=0x44a runnable [0x0000000000000000..0x0000000000000000]
>   java.lang.Thread.State: RUNNABLE
>
> "CompilerThread1" daemon prio=10 tid=0x00007f783c025800 nid=0x449  
> waiting on condition [0x0000000000000000..0x00007f783bdfb230]
>   java.lang.Thread.State: RUNNABLE
>
> "CompilerThread0" daemon prio=10 tid=0x00007f783c023800 nid=0x448  
> waiting on condition [0x0000000000000000..0x00007f783befc2b0]
>   java.lang.Thread.State: RUNNABLE
>
> "Signal Dispatcher" daemon prio=10 tid=0x00007f783c021800 nid=0x447  
> waiting on condition [0x0000000000000000..0x0000000000000000]
>   java.lang.Thread.State: RUNNABLE
>
> "Finalizer" daemon prio=10 tid=0x00007f783c001000 nid=0x446 in  
> Object.wait() [0x00007f7840189000..0x00007f7840189b70]
>   java.lang.Thread.State: WAITING (on object monitor)
> 	at java.lang.Object.wait(Native Method)
> 	- waiting on <0x00007f784b682b68> (a java.lang.ref.ReferenceQueue 
> $Lock)
> 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:133)
> 	- locked <0x00007f784b682b68> (a java.lang.ref.ReferenceQueue$Lock)
> 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:149)
> 	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177)
>
> "Reference Handler" daemon prio=10 tid=0x0000000000db2800 nid=0x445  
> waiting for monitor entry [0x00007f784028a000..0x00007f784028abf0]
>   java.lang.Thread.State: BLOCKED (on object monitor)
> 	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:126)
> 	- waiting to lock <0x00007f784bb954f8> (a java.lang.ref.Reference 
> $Lock)
>
> "main" prio=10 tid=0x0000000000d4a000 nid=0x441 waiting on condition  
> [0x00007f78c13aa000..0x00007f78c13aae90]
>   java.lang.Thread.State: TIMED_WAITING (sleeping)
> 	at java.lang.Thread.sleep(Native Method)
> 	at uk.me.parabola.mkgmap.main.Main.endOptions(Main.java:310)
> 	at uk.me.parabola.mkgmap.CommandArgsReader.readArgs 
> (CommandArgsReader.java:124)
> 	at uk.me.parabola.mkgmap.main.Main.main(Main.java:118)
>
> "VM Thread" prio=10 tid=0x0000000000dae000 nid=0x444 runnable
>
> "GC task thread#0 (ParallelGC)" prio=10 tid=0x0000000000d54000  
> nid=0x442 runnable
>
> "GC task thread#1 (ParallelGC)" prio=10 tid=0x0000000000d56000  
> nid=0x443 runnable
>
> "VM Periodic Task Thread" prio=10 tid=0x00007f783c02b800 nid=0x44b  
> waiting on condition
>
> JNI global references: 863
>
> Heap
> PSYoungGen      total 222912K, used 30912K [0x00007f7896110000,  
> 0x00007f78afee0000, 0x00007f78bb660000)
>  eden space 30912K, 100% used  
> [0x00007f7896110000,0x00007f7897f40000,0x00007f7897f40000)
>  from space 192000K, 0% used  
> [0x00007f78a4360000,0x00007f78a4360000,0x00007f78afee0000)
>  to   space 196416K, 0% used  
> [0x00007f7897f40000,0x00007f7897f40000,0x00007f78a3f10000)
> PSOldGen        total 1223360K, used 1221420K [0x00007f784b660000,  
> 0x00007f7896110000, 0x00007f7896110000)
>  object space 1223360K, 99% used  
> [0x00007f784b660000,0x00007f7895f2b358,0x00007f7896110000)
> PSPermGen       total 21248K, used 6198K [0x00007f7840e60000,  
> 0x00007f7842320000, 0x00007f784b660000)
>  object space 21248K, 29% used  
> [0x00007f7840e60000,0x00007f784146d8b0,0x00007f7842320000)
>
>
>
> _______________________________________________
> mkgmap-dev mailing list
> mkgmap-dev at lists.mkgmap.org.uk
> http://www.mkgmap.org.uk/mailman/listinfo/mkgmap-dev