This article is participating in the Java Theme Month – Java Debug Notes Event, see the event link for details

1. Background

A very frequently invoked method with synchronized crashes the program

Simulating the occurrence of accidents

  1. Create a thread pool to simulate multi-user access

    ThreadPoolExecutor ThreadPoolExecutor = new ThreadPoolExecutor (10,10,0 L, TimeUnit MICROSECONDS, new ArrayBlockingQueue<>(10)); for (int i = 0; i <1000; i++) { threadPoolExecutor.execute(()->{ testSync(); }); } public static synchronized void testSync(){try {system.out.println ("Hi thread pool "); Thread.sleep(30000); } catch (InterruptedException e) { e.printStackTrace(); }}Copy the code

    The following error occurs

    Exception in thread "main" java.util.concurrent.RejectedExecutionException: Task com.sunisco.collect.ugqd.web.pages.Test$$Lambda$1/1642360923@6aa8ceb6 rejected from java.util.concurrent.ThreadPoolExecutor@2530c12[Running, pool size = 10, active threads = 10, queued tasks = 10, completed tasks = 0]
            at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
            at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
            at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379)
            at com.sunisco.collect.ugqd.web.pages.Test.main(Test.java:24)
        
        
    Copy the code

    This is because the number of runs is greater than the number of queues, and tests continue after modification

    ThreadPoolExecutor ThreadPoolExecutor = new ThreadPoolExecutor (10,10,0 L, TimeUnit MICROSECONDS, new ArrayBlockingQueue<>(100)); for (int i = 0; i <100; i++) { threadPoolExecutor.execute(()->{ testSync(); }); } public static synchronized void testSync(){try {system.out.println ("Hi thread pool "); Thread.sleep(30000); } catch (InterruptedException e) { e.printStackTrace(); }}Copy the code

    The output is as follows

  1. Through JPS to view all the system Java process PID, find our program PID 12308

    C:\Users\Administrator>jps 11088 RemoteMavenServer 8352 Test 12308 Test 10632 Launcher 9384 Launcher 11100 6572 Jps 9180  TestCopy the code
  2. Run the jStack 12308 command to view information about the threads in the process

     C:\Users\Administrator>jstack 12308
     2021-05-13 09:34:53
     Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.141-b15 mixed mode):
    
     "DestroyJavaVM" #21 prio=5 os_prio=0 tid=0x000000001ec4f800 nid=0x27bc waiting on condition [0x0000000000000000]
        java.lang.Thread.State: RUNNABLE
    
     "pool-1-thread-10" #20 prio=5 os_prio=0 tid=0x000000001ec4e000 nid=0x1650 waiting for monitor entry [0x000000001ff8f000]
        java.lang.Thread.State: BLOCKED (on object monitor)
             at com.sunisco.collect.ugqd.web.pages.Test.getg(Test.java:55)
             - waiting to lock <0x000000076b740d80> (a java.lang.Class for com.sunisco.collect.ugqd.web.pages.Test)
             at com.sunisco.collect.ugqd.web.pages.Test.lambda$main$0(Test.java:27)
             at com.sunisco.collect.ugqd.web.pages.Test$$Lambda$1/1642360923.run(Unknown Source)
             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)
    
     "pool-1-thread-9" #19 prio=5 os_prio=0 tid=0x000000001ec4a000 nid=0x2a88 waiting on condition [0x000000001fe8f000]
        java.lang.Thread.State: TIMED_WAITING (sleeping)
             at java.lang.Thread.sleep(Native Method)
             at com.sunisco.collect.ugqd.web.pages.Test.getg(Test.java:56)
             - locked <0x000000076b740d80> (a java.lang.Class for com.sunisco.collect.ugqd.web.pages.Test)
             at com.sunisco.collect.ugqd.web.pages.Test.lambda$main$0(Test.java:27)
             at com.sunisco.collect.ugqd.web.pages.Test$$Lambda$1/1642360923.run(Unknown Source)
             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)
    
    
    
    
     "pool-1-thread-2" #12 prio=5 os_prio=0 tid=0x000000001ea78000 nid=0x1250 waiting for monitor entry [0x000000001f78f000]
        java.lang.Thread.State: BLOCKED (on object monitor)
             at com.sunisco.collect.ugqd.web.pages.Test.getg(Test.java:55)
             - waiting to lock <0x000000076b740d80> (a java.lang.Class for com.sunisco.collect.ugqd.web.pages.Test)
             at com.sunisco.collect.ugqd.web.pages.Test.lambda$main$0(Test.java:27)
             at com.sunisco.collect.ugqd.web.pages.Test$$Lambda$1/1642360923.run(Unknown Source)
             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)
    
     "pool-1-thread-1" #11 prio=5 os_prio=0 tid=0x000000001ec11800 nid=0xa38 waiting for monitor entry [0x000000001f68f000]
        java.lang.Thread.State: BLOCKED (on object monitor)
             at com.sunisco.collect.ugqd.web.pages.Test.getg(Test.java:55)
             - waiting to lock <0x000000076b740d80> (a java.lang.Class for com.sunisco.collect.ugqd.web.pages.Test)
             at com.sunisco.collect.ugqd.web.pages.Test.lambda$main$0(Test.java:27)
             at com.sunisco.collect.ugqd.web.pages.Test$$Lambda$1/1642360923.run(Unknown Source)
             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)
    
     "Service Thread" #10 daemon prio=9 os_prio=0 tid=0x000000001e93c000 nid=0x226c runnable [0x0000000000000000]
        java.lang.Thread.State: RUNNABLE
    
     "C1 CompilerThread2" #9 daemon prio=9 os_prio=2 tid=0x000000001e8c9800 nid=0x21d8 waiting on condition [0x0000000000000000]
        java.lang.Thread.State: RUNNABLE
     "Monitor Ctrl-Break" #6 daemon prio=5 os_prio=0 tid=0x000000001e84b000 nid=0x1c4c runnable [0x000000001f08e000]
        java.lang.Thread.State: RUNNABLE
             at java.net.SocketInputStream.socketRead0(Native Method)
             at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
             at java.net.SocketInputStream.read(SocketInputStream.java:171)
             at java.net.SocketInputStream.read(SocketInputStream.java:141)
             at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
             at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
             at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
             - locked <0x000000076b82f3e0> (a java.io.InputStreamReader)
             at java.io.InputStreamReader.read(InputStreamReader.java:184)
             at java.io.BufferedReader.fill(BufferedReader.java:161)
             at java.io.BufferedReader.readLine(BufferedReader.java:324)
             - locked <0x000000076b82f3e0> (a java.io.InputStreamReader)
             at java.io.BufferedReader.readLine(BufferedReader.java:389)
             at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)
    
     "Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001cdf9800 nid=0x35ec waiting on condition [0x0000000000000000]
        java.lang.Thread.State: RUNNABLE
    
     "Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001cde4800 nid=0x34e8 runnable [0x0000000000000000]
        java.lang.Thread.State: RUNNABLE
    
     "Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001cdbf000 nid=0x54c in Object.wait() [0x000000001e12f000]
        java.lang.Thread.State: WAITING (on object monitor)
             at java.lang.Object.wait(Native Method)
             - waiting on <0x000000076b188ec8> (a java.lang.ref.ReferenceQueue$Lock)
             at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
             - locked <0x000000076b188ec8> (a java.lang.ref.ReferenceQueue$Lock)
             at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
             at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
    
     "Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x0000000003687000 nid=0x3318 in Object.wait() [0x000000001e02e000]
        java.lang.Thread.State: WAITING (on object monitor)
             at java.lang.Object.wait(Native Method)
             - waiting on <0x000000076b186b68> (a java.lang.ref.Reference$Lock)
             at java.lang.Object.wait(Object.java:502)
             at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
             - locked <0x000000076b186b68> (a java.lang.ref.Reference$Lock)
             at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
    
     "VM Thread" os_prio=2 tid=0x000000001cd97800 nid=0x2d1c runnable
    
     "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00000000035ad000 nid=0x1efc runnable
    
     "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00000000035ae800 nid=0xa50 runnable
    
     "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00000000035b1000 nid=0x1bac runnable
    
     "GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00000000035b3000 nid=0x2d50 runnable
    
     "VM Periodic Task Thread" os_prio=2 tid=0x000000001ea1a800 nid=0x27f4 waiting on condition
    
     JNI global references: 335
    Copy the code

The jStack log shows that there are many block-state threads, and the production problem is that there are too many block-state threads, which cause the program to crash.

Three conclusion

Locking is an effective way to handle data inconsistencies caused by concurrency, but it can have a significant impact on performance if not used properly, so be careful before using it.