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

Mon Sep 28 17:08:29 BST 2009

Thanks for sharing this. Good to know that I don't have to buy a 
quadcore yet :-)

Apollinaris Schoell wrote:
> 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
> 
> _______________________________________________
> mkgmap-dev mailing list
> mkgmap-dev at lists.mkgmap.org.uk
> http://www.mkgmap.org.uk/mailman/listinfo/mkgmap-dev