a pit of infinite loopeness
배경
Server scale-up 이후부터 Web Application을 배포하고 나면 몇시간 이내에 특정 서버의 CPU 사용률이 100%에 이르는 사태가 발생하였다. thread dump를 확인해 봐도 특별한 이상 징후는 발견되지 않았다. 단지 아래와 같이 여러 Thread 들이 java.util.WeakHashMap.get(WeakHashMap.java:355) 에 걸려있었으나, Thread.State가 RUNNABLE 이기 때문에 주의깊게 보지 않았다. 왜냐하면 지금까지 Java core package에서 문제가 발생한 적은 한 번도 없거니와, Java core package를 의심하게 되면 밑도끝도 없이 모든것을 의심해야 하는 불상사가 발생하기 때문이다. 난 적어도 절친은 믿고 세상을 살아간다. 훗날 내 뒤통수를 칠 지언정…
"TP-Processor233" daemon prio=10 tid=0x8d848800 nid=0x717d runnable [0x893f6000]
java.lang.Thread.State: RUNNABLE
at java.util.WeakHashMap.get(WeakHashMap.java:355)
at com.thoughtworks.xstream.io.xml.XmlFriendlyReplacer.unescapeName(XmlFriendlyReplacer.java:118)
at com.thoughtworks.xstream.io.xml.AbstractXmlReader.unescapeXmlName(AbstractXmlReader.java:42)
at com.thoughtworks.xstream.io.xml.AbstractPullReader.getNodeName(AbstractPullReader.java:199)
at com.thoughtworks.xstream.io.ReaderWrapper.getNodeName(ReaderWrapper.java:44)
at com.thoughtworks.xstream.io.path.PathTrackingReader.moveDown(PathTrackingReader.java:38)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doUnmarshal(AbstractReflectionConverter.java:199)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshal(AbstractReflectionConverter.java:162)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:82)
at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:63)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:76)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshallField(AbstractReflectionConverter.java:246)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doUnmarshal(AbstractReflectionConverter.java:218)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshal(AbstractReflectionConverter.java:162)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:82)
at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:63)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:76)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:60)
at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:137)
at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:33)
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:923)
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:909)
at com.thoughtworks.xstream.XStream.fromXML(XStream.java:861)
문제가 된 web application에서 사용하는 XStream의 version이 1.3인데, 혹시나 하는 마음에 공식 XStream site에 들어가서 change history를 보다가 XSTR-584: Race condition in XmlFriendlyReplacer issue를 발견했다. Issue description 에는 내가 겪은 증상과 동일했고, 문제의 원인은 not synchronized java.util.WeakHashMap 을 사용했기 때문이라고 간단히 쓰여 있었다.
com.thoughtworks.xstream.io.xml.XmlFriendlyReplacer makes use of 2 WeakHashmaps to hold string.
Those maps are accessed multi-threaded, but are not synchronized.This can lead to access on those maps occupying all CPU-resources, which can only get solved by restarting the VM.
This happens under rare heavily multi-threaded circumstances, nevertheless the impact is critical.
Implementation of java.util.Map이 가진 잠재적 문제점
구글링을 해보니 Multi-threaded situation(under high concurrency) 에서 Implementation of java.util.Map 의 get() 호출 시 method 내부에서 infinite loop에 빠질 수 있다고 한다. 해당 되는 Implementation of java.util.Map 는 API Document에 아래와 같이 설명된 Class 들이다.
Note that this implementation is not synchronized. If multiple threads access a hash map concurrently, and at least one of the threads modifies the map structurally, it must be synchronized externally. (A structural modification is any operation that adds or deletes one or more mappings; merely changing the value associated with a key that an instance already contains is not a structural modification.) This is typically accomplished by synchronizing on some object that naturally encapsulates the map. If no such object exists, the map should be “wrapped” using the Collections.synchronizedMap method. This is best done at creation time, to prevent accidental unsynchronized access to the map:
Map m = Collections.synchronizedMap(new HashMap(…));
- java.util.HashMap
- java.util.LinkedHashMap
- java.util.TreeMap
- java.util.WeakHashMap
더욱이 문제는 대부분의 개발자들은 concurrency로 인한 data corruption 을 염두해두고 위 Class들을 자주 사용한다는 점이다. 즉 개발자가 Java Document의 “Note that this implementation is not synchronized” 의 의미를 race condition 에 의한 data corruption 까지만 이해하고 위 Class들을 자주 사용할수록, infinite loop에 빠질 확률이 더 높아진다.
그 결과 JVM hanging 뿐만 아니라 해당 서버에서 제공하는 서비스들(i.e daemon)까지도 CPU 자원을 사용할 수 없기 때문에 문제는 더욱 커진다. 이렇게 불시에 찾아와 CPU 자원을 모두 고갈시키는 불청객의 위험이 우리 주위에 도사리고 있다.
어느 CS 전공자가 위 Note만 보고 JVM이 hanging 될꺼라 예상할 수 있을까? 5년 넘게 Java language 의 API들을 많이 사용해 왔지만, 위 처럼 황당한 경우는 처음이다. 최소한 infinite loop 에 대한 경고는 해야 하지 않았을까? Synchronization에 따른 deadlock은 들어 봤어도, not synchronization에 따른 infinite loop는 들어 본 적이 없다.
언제 infinite loop가 발생하는가?
기가 막히게 제목을 잘 지은 “A Beautiful Race Condition” article 에서 infinite loop가 언제 발생할 수 있는지에 대해 설명이 잘 되어 있다.
java.util.HashMap.transfer() 를 호출하고 난 뒤 Entry[] table의 상태를 그려보았다.
- normal case
- abnormal case
- 2개 이상의 thread가 Map에 동시에 write할 때 rehash의 조건이 true 이면
- Map의 어느 bucket의 Entry.next 가 서로를 가리킨다. infinite loop 생성
- infinite loop Entry가 있는 bucket 을 read 할 때 해당 thread는 hanging
대응 방법
- java.util.concurrent.ConcurrentHashMap 사용
- Collections.synchronizedMap method 사용하여 wrapping
- mutator method 에 접근 할 때 synchronized 처리
이거땜에 고생햇는데.. 통쾌한 포스팅 잘보고갑니다.