On Mon, Jul 22, 2019, 16:08 Prakhar Mathur <prakha...@go-jek.com> wrote:
> Hi, > > We enabled GC logging, here are the logs > > [GC (Allocation Failure) [PSYoungGen: 6482015K->70303K(6776832K)] > 6955827K->544194K(20823552K), 0.0591479 secs] [Times: user=0.09 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6587039K->38642K(6763008K)] > 7060930K->512614K(20809728K), 0.0740978 secs] [Times: user=0.08 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6502858K->192077K(6734848K)] > 6976829K->666144K(20781568K), 0.0841759 secs] [Times: user=0.17 sys=0.00, > real=0.09 secs] > [GC (Allocation Failure) [PSYoungGen: 6647378K->50108K(6759424K)] > 7121446K->524248K(20806144K), 0.0622997 secs] [Times: user=0.08 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6501890K->60606K(6779904K)] > 6976029K->534961K(20826624K), 0.0637955 secs] [Times: user=0.09 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6586046K->40411K(6768640K)] > 7060401K->514839K(20815360K), 0.0729137 secs] [Times: user=0.08 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6543919K->51886K(6797824K)] > 7018346K->526385K(20844544K), 0.0649143 secs] [Times: user=0.09 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6601690K->191832K(6754304K)] > 7076190K->666427K(20801024K), 0.1029686 secs] [Times: user=0.18 sys=0.00, > real=0.10 secs] > [GC (Allocation Failure) [PSYoungGen: 6742947K->62693K(6781952K)] > 7217543K->537361K(20828672K), 0.0639272 secs] [Times: user=0.09 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6589986K->66299K(6770688K)] > 7064653K->541039K(20817408K), 0.0701853 secs] [Times: user=0.08 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6590742K->42995K(6800896K)] > 7065481K->517798K(20847616K), 0.0595729 secs] [Times: user=0.08 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6608678K->66127K(6793728K)] > 7083482K->541011K(20840448K), 0.0608270 secs] [Times: user=0.09 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6608886K->62063K(6822400K)] > 7083769K->537027K(20869120K), 0.0675917 secs] [Times: user=0.10 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6617146K->200674K(6812160K)] > 7092110K->812325K(20858880K), 1.1685237 secs] [Times: user=3.53 sys=0.71, > real=1.17 secs] > [GC (Allocation Failure) [PSYoungGen: 6773610K->194848K(6633984K)] > 7385261K->806700K(20680704K), 0.0858601 secs] [Times: user=0.19 sys=0.00, > real=0.09 secs] > [GC (Allocation Failure) [PSYoungGen: 6617888K->44002K(6723072K)] > 7229740K->655854K(20769792K), 0.0647387 secs] [Times: user=0.09 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6420043K->194672K(6702080K)] > 7031895K->806604K(20748800K), 0.0833792 secs] [Times: user=0.18 sys=0.00, > real=0.08 secs] > [GC (Allocation Failure) [PSYoungGen: 6603376K->187059K(6596096K)] > 7215308K->799063K(20642816K), 0.0906529 secs] [Times: user=0.17 sys=0.00, > real=0.09 secs] > [GC (Allocation Failure) [PSYoungGen: 6572690K->51850K(6715904K)] > 7184694K->663990K(20762624K), 0.0837285 secs] [Times: user=0.11 sys=0.00, > real=0.09 secs] > [GC (Allocation Failure) [PSYoungGen: 6452380K->44766K(6708224K)] > 7064519K->656993K(20754944K), 0.0809864 secs] [Times: user=0.10 sys=0.00, > real=0.08 secs] > [GC (Allocation Failure) [PSYoungGen: 6445790K->42654K(6730752K)] > 7058017K->654961K(20777472K), 0.0686401 secs] [Times: user=0.08 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6473374K->41410K(6723072K)] > 7085681K->654085K(20769792K), 0.0714228 secs] [Times: user=0.08 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6448507K->59031K(6752256K)] > 7061182K->671786K(20798976K), 0.0599829 secs] [Times: user=0.09 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6489819K->68484K(6739968K)] > 7102574K->681619K(20786688K), 0.0674541 secs] [Times: user=0.09 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6537251K->257001K(6625792K)] > 7150386K->938268K(20672512K), 1.1775771 secs] [Times: user=4.11 sys=0.22, > real=1.18 secs] > [GC (Allocation Failure) [PSYoungGen: 6575609K->76090K(6695936K)] > 7256876K->757765K(20742656K), 0.0805662 secs] [Times: user=0.11 sys=0.01, > real=0.08 secs] > [GC (Allocation Failure) [PSYoungGen: 6444858K->42242K(6719488K)] > 7126533K->723917K(20766208K), 0.0611949 secs] [Times: user=0.09 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6399332K->143985K(6710784K)] > 7081006K->826084K(20757504K), 0.0771257 secs] [Times: user=0.16 sys=0.00, > real=0.08 secs] > [GC (Allocation Failure) [PSYoungGen: 6503905K->67207K(6736896K)] > 7186004K->750758K(20783616K), 0.0808856 secs] [Times: user=0.11 sys=0.01, > real=0.08 secs] > [GC (Allocation Failure) [PSYoungGen: 6468318K->59200K(6724608K)] > 7151869K->743099K(20771328K), 0.0709461 secs] [Times: user=0.09 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6484294K->51134K(6757376K)] > 7168193K->735120K(20804096K), 0.0772947 secs] [Times: user=0.11 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6503020K->77337K(6747648K)] > 7187007K->761395K(20794368K), 0.0835827 secs] [Times: user=0.12 sys=0.00, > real=0.09 secs] > [GC (Allocation Failure) [PSYoungGen: 6505125K->66972K(6783488K)] > 7189184K->751110K(20830208K), 0.0671168 secs] [Times: user=0.09 sys=0.00, > real=0.06 secs] > [GC (Allocation Failure) [PSYoungGen: 6544467K->201750K(6734336K)] > 7228606K->885969K(20781056K), 0.0931485 secs] [Times: user=0.20 sys=0.00, > real=0.10 secs] > [GC (Allocation Failure) [PSYoungGen: 6733846K->43858K(6763520K)] > 7418065K->728157K(20810240K), 0.0683046 secs] [Times: user=0.09 sys=0.00, > real=0.07 secs] > [GC (Allocation Failure) [PSYoungGen: 6525200K->66239K(6756864K)] > 7209498K->750617K(20803584K), 0.0764187 secs] [Times: user=0.10 sys=0.00, > real=0.08 secs] > > > We were going through the thread dump, but couldn't find a reason for such > behaviour > > "flink-rest-server-netty-worker-thread-8" - Thread t@126233 > java.lang.Thread.State: RUNNABLE > at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) > at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) > - locked <2654bbbf> (a > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySet) > - locked <45bd4356> (a java.util.Collections$UnmodifiableSet) > - locked <24d4aa0> (a sun.nio.ch.EPollSelectorImpl) > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:765) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:413) > at > org.apache.flink.shaded.netty4.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) > at java.lang.Thread.run(Thread.java:748) > > Locked ownable synchronizers: > - None > > "flink-rest-server-netty-worker-thread-7" - Thread t@123834 > java.lang.Thread.State: RUNNABLE > at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) > at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) > - locked <2a9b97d7> (a > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySet) > - locked <29115878> (a java.util.Collections$UnmodifiableSet) > - locked <61909ff> (a sun.nio.ch.EPollSelectorImpl) > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:765) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:413) > at > org.apache.flink.shaded.netty4.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) > at java.lang.Thread.run(Thread.java:748) > > Locked ownable synchronizers: > - None > > "flink-rest-server-netty-worker-thread-6" - Thread t@121404 > java.lang.Thread.State: RUNNABLE > at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) > at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) > - locked <6ee94bd6> (a > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySet) > - locked <183a4cf3> (a java.util.Collections$UnmodifiableSet) > - locked <3b4b1514> (a sun.nio.ch.EPollSelectorImpl) > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:765) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:413) > at > org.apache.flink.shaded.netty4.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) > at java.lang.Thread.run(Thread.java:748) > > Locked ownable synchronizers: > - None > > "flink-rest-server-netty-worker-thread-5" - Thread t@118945 > java.lang.Thread.State: RUNNABLE > at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) > at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) > - locked <7553b573> (a > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySet) > - locked <51c0f7f4> (a java.util.Collections$UnmodifiableSet) > - locked <1bd774eb> (a sun.nio.ch.EPollSelectorImpl) > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:765) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:413) > at > org.apache.flink.shaded.netty4.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) > at java.lang.Thread.run(Thread.java:748) > > Locked ownable synchronizers: > - None > > "flink-rest-server-netty-worker-thread-4" - Thread t@117073 > java.lang.Thread.State: RUNNABLE > at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) > at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) > - locked <78572130> (a > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySet) > - locked <1047fb64> (a java.util.Collections$UnmodifiableSet) > - locked <466ec1cf> (a sun.nio.ch.EPollSelectorImpl) > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:765) > at > org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:413) > at > org.apache.flink.shaded.netty4.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) > at java.lang.Thread.run(Thread.java:748) > > Locked ownable synchronizers: > - None > > "gcs-async-channel-pool-19" - Thread t@116997 > java.lang.Thread.State: TIMED_WAITING > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <1be52a4a> (a > java.util.concurrent.SynchronousQueue$TransferStack) > at > java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) > at > java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) > at > java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) > at > java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) > at > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) > at java.lang.Thread.run(Thread.java:748) > > Locked ownable synchronizers: > - None > > "RMI TCP Connection(36)-127.0.0.1" - Thread t@114070 > java.lang.Thread.State: TIMED_WAITING > at java.lang.Object.wait(Native Method) > - waiting on <22b14b0b> (a > com.sun.jmx.remote.internal.ArrayNotificationBuffer) > at > com.sun.jmx.remote.internal.ArrayNotificationBuffer.fetchNotifications(ArrayNotificationBuffer.java:449) > at > com.sun.jmx.remote.internal.ArrayNotificationBuffer$ShareBuffer.fetchNotifications(ArrayNotificationBuffer.java:227) > at > com.sun.jmx.remote.internal.ServerNotifForwarder.fetchNotifs(ServerNotifForwarder.java:274) > at > javax.management.remote.rmi.RMIConnectionImpl$4.run(RMIConnectionImpl.java:1270) > at > javax.management.remote.rmi.RMIConnectionImpl$4.run(RMIConnectionImpl.java:1268) > at > javax.management.remote.rmi.RMIConnectionImpl.fetchNotifications(RMIConnectionImpl.java:1274) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:498) > at > sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357) > at sun.rmi.transport.Transport$1.run(Transport.java:200) > at sun.rmi.transport.Transport$1.run(Transport.java:197) > at java.security.AccessController.doPrivileged(Native Method) > at sun.rmi.transport.Transport.serviceCall(Transport.java:196) > at > sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:573) > at > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:834) > at > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:688) > at > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$592/690739656.run(Unknown > Source) > at java.security.AccessController.doPrivileged(Native Method) > at > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:687) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) > at java.lang.Thread.run(Thread.java:748) > > On Thu, Jul 18, 2019 at 12:25 PM Biao Liu <mmyy1...@gmail.com> wrote: > >> Hi, >> >> It seems to be good based on your GC metrics. You could double check the >> GC log if you enable it. The GC log is more direct. >> I'm not sure what's happening in your JobManager. But I'm pretty sure >> that Flink could support far more larger scale cluster than yours. >> >> Have you ever checked the log file of JobManager? Is there any suspicious >> warning or error log? >> Have you ever tried some analytic tools to check the internal state of >> JobManager, like jstack. >> >> It's hard to do a deeper analysis based on current informations. It might >> be helpful if you could provide more details. >> >> >> Prakhar Mathur <prakha...@go-jek.com> 于2019年7月18日周四 下午2:12写道： >> >>> Hi, >>> >>> We are using v1.6.2, currently, the number of TaskManagers are 70. We >>> have the GC metrics on a dashboard also. Sum of >>> Status.JVM.GarbageCollector.MarkSweepCompact.Time grouped by 1 min is >>> somewhere between 75 to 125 >>> and Status.JVM.GarbageCollector.MarkSweepCompact.Count is fixed at 10. >>> >>> On Thu, Jul 18, 2019 at 11:32 AM Biao Liu <mmyy1...@gmail.com> wrote: >>> >>>> Hi Prakhar, >>>> >>>> Have you ever checked the garbage collection of master? >>>> Which version of Flink are you using? How many TaskManagers in your >>>> cluster? >>>> >>>> >>>> Prakhar Mathur <prakha...@go-jek.com> 于2019年7月18日周四 下午1:54写道： >>>> >>>>> Hello, >>>>> >>>>> We have deployed multiple Flink clusters on Kubernetess with 1 replica >>>>> of Jobmanager and multiple of Taskmanager as per the requirement. Recently >>>>> we are observing that on increasing the number of Taskmanagers for a >>>>> cluster, the Jobmanager becomes irresponsive. It stops sending statsd >>>>> metric for some irregular interval. Even the Jobmanager pod keeps >>>>> restarting because it stops responding to the liveliness probe which >>>>> results in Kubernetes killing the pod. We tried increasing the resources >>>>> given(CPU, RAM) but it didn't help. >>>>> >>>>> Regards >>>>> Prakhar Mathur >>>>> Product Engineer >>>>> GO-JEK >>>>> >>>>
