java代码执行在没有断点和正常运行的调试中产生不同的结果。 ExecutorService 坏了吗?
Posted
技术标签:
【中文标题】java代码执行在没有断点和正常运行的调试中产生不同的结果。 ExecutorService 坏了吗?【英文标题】:java code execution yields to different results in debug without breakpoints and normal run. Is ExecutorService broken? 【发布时间】:2016-11-16 05:07:22 【问题描述】:TL:DR ExecutorService executorService = Executors.newFixedThreadPool(8);
在调试中运行并发,但在正常运行时它开始并发,但后来在单线程中运行。
我有一些代码可以在ExecutorService
中启动 4 个不同的任务。其中两个任务应该几乎立即完成,另外两个应该运行一段时间。
这些任务在Future<Double>
中返回以秒为单位的执行时间。
这段代码负责任务执行和测量:
public Future<Double> measure(int[] arr, ProcessIntArray processIntArray, ExecutorService es)
Callable<Double> task = () ->
long start = System.nanoTime();
processIntArray.process(arr);
long end = System.nanoTime();
return (end - start) / 1000000000.0;
;
return es.submit(task);
稍后,在启动这些任务后,我会按照之前运行的执行时间顺序打印它们,输入大小相同。
Future<Double> bubbleSortTime = measure(bubbleSortArray, Solution::bubbleSort, executorService);
Future<Double> insertionSortTime = measure(insertionSortArray, Solution::insertionSort, executorService);
Future<Double> quickSortTime = measure(quickSortArray, Solution::quickSort, executorService);
Future<Double> mergeSortTime = measure(mergeSortArray, Solution::mergeSort, executorService);
System.out.println();
System.out.println("array size: " + size);
System.out.println("quick sort: " + quickSortTime.get() + "s");
System.out.println("merge sort: " + mergeSortTime.get() + "s");
System.out.println("insertion sort: " + insertionSortTime.get() + "s");
System.out.println("bubble sort: " + bubbleSortTime.get() + "s");
当我在调试模式下运行代码时,会立即打印 2 个结果,我必须等待一段时间才能获得第 3 个结果(我不费心等待第 4 个结果)。
开始调试后(正确且符合预期):
array size: 1000000
quick sort: 0.186892839s
merge sort: 0.291950604s
insertion sort: 344.534256723s
正常执行不同,看起来在方法 measure long start = System.nanoTime();
中执行了,然后线程进入休眠状态,并且在 insertSort 完成后,quickSort 重新执行,这产生了输出:
array size: 1000000
quick sort: 345.893922141s
merge sort: 345.944023095s
insertion sort: 345.871908569s
这是错误的。所有这些线程都应该同时运行,就像从 newFixedThreadPool javadoc 中一样。
/**
* Creates a thread pool that reuses a fixed number of threads
* operating off a shared unbounded queue. At any point, at most
* @code nThreads threads will be active processing tasks.
* If additional tasks are submitted when all threads are active,
* they will wait in the queue until a thread is available.
* If any thread terminates due to a failure during execution
* prior to shutdown, a new one will take its place if needed to
* execute subsequent tasks. The threads in the pool will exist
* until it is explicitly @link ExecutorService#shutdown shutdown.
*
* @param nThreads the number of threads in the pool
* @return the newly created thread pool
* @throws IllegalArgumentException if @code nThreads <= 0
*/
public static ExecutorService newFixedThreadPool(int nThreads)
我附上源代码:
import java.util.Arrays;
import java.util.Random;
import java.util.concurrent.*;
class ThreadedSortingComparsion
Random random = new Random(System.currentTimeMillis());
void popul(int[] array)
for (int i = 0; i < array.length; i++)
array[i] = random.nextInt();
interface ArraySorter
void sort(int[] array);
public Future<Double> measureTime(int[] array, ArraySorter arraySorter, ExecutorService executorService)
Callable<Double> task = () ->
long start = System.nanoTime();
arraySorter.sort(array);
long end = System.nanoTime();
return (end - start) / 1000000000.0;
;
return executorService.submit(task);
public void start() throws ExecutionException, InterruptedException
ExecutorService executorService = Executors.newFixedThreadPool(8);
int size = 1000 * 1000;
int[] quickSortArray = new int[size];
popul(quickSortArray);
int[] bubbleSortArray = Arrays.copyOf(quickSortArray, quickSortArray.length);
int[] mergeSortArray = Arrays.copyOf(quickSortArray, quickSortArray.length);
int[] originalArray = Arrays.copyOf(quickSortArray, quickSortArray.length);
int[] insertionSortArray = Arrays.copyOf(quickSortArray, quickSortArray.length);
Future<Double> bubbleSortTime = measureTime(bubbleSortArray, ThreadedSortingComparsion::bubbleSort, executorService);
Future<Double> insertionSortTime = measureTime(insertionSortArray, ThreadedSortingComparsion::insertionSort, executorService);
Future<Double> quickSortTime = measureTime(quickSortArray, ThreadedSortingComparsion::quickSort, executorService);
Future<Double> mergeSortTime = measureTime(mergeSortArray, ThreadedSortingComparsion::mergeSort, executorService);
System.out.println();
System.out.println("array size: " + size);
System.out.println("quick sort: " + quickSortTime.get() + "s");
System.out.println("merge sort: " + mergeSortTime.get() + "s");
System.out.println("insertion sort: " + insertionSortTime.get() + "s");
System.out.println("bubble sort: " + bubbleSortTime.get() + "s");
executorService.shutdown();
for (int i = 0; i < quickSortArray.length; i++)
if (quickSortArray[i] != bubbleSortArray[i] || quickSortArray[i] != mergeSortArray[i] || quickSortArray[i] != insertionSortArray[i])
throw new RuntimeException(Arrays.toString(originalArray));
public static void mergeSort(int[] ar)
if (ar.length < 5)
bubbleSort(ar);
return;
int middle = ar.length / 2;
int[] arrayLeft = new int[middle];
int[] arrayRight = new int[ar.length - middle];
for (int i = 0; i < ar.length; i++)
if (i < middle)
arrayLeft[i] = ar[i];
else
arrayRight[i - middle] = ar[i];
mergeSort(arrayLeft);
mergeSort(arrayRight);
int indexLeft = 0;
int indexRight = 0;
int inputArrayIndex = 0;
while (true)
int whatToPutInAR = 0;
if (indexLeft != arrayLeft.length && indexRight != arrayRight.length)
if (arrayLeft[indexLeft] < arrayRight[indexRight])
whatToPutInAR = arrayLeft[indexLeft];
indexLeft++;
else
whatToPutInAR = arrayRight[indexRight];
indexRight++;
else if (indexLeft != arrayLeft.length)
whatToPutInAR = arrayLeft[indexLeft];
indexLeft++;
else if (indexRight != arrayRight.length)
whatToPutInAR = arrayRight[indexRight];
indexRight++;
if (inputArrayIndex == ar.length) return;
ar[inputArrayIndex++] = whatToPutInAR;
private static void quickSort(int[] ar)
quickSort(ar, 0, ar.length);
static public void quickSort(int[] array, int start, int end)
boolean changed = false;
if (end == 0) return;
int pivot = array[end - 1];
int partitionCandidate = start;
for (int i = start; i < end; i++)
if (array[i] < pivot)
swap(array, partitionCandidate++, i);
changed = true;
else if (pivot < array[i])
swap(array, end - 1, i);
changed = true;
if (start < partitionCandidate)
quickSort(array, start, partitionCandidate);
if (partitionCandidate < end)
if (partitionCandidate != start || changed) quickSort(array, partitionCandidate, end);
public static void swap(int[] ar, int from, int to)
int old = ar[from];
ar[from] = ar[to];
ar[to] = old;
public static void bubbleSort(int[] array)
for (int i = 0; i < array.length; i++)
for (int j = 0; j < array.length - 1; j++)
if (array[j] > array[j + 1])
swap(array, j + 1, j);
private static void insertionSort(int[] ar)
for (int i = 0; i < ar.length; i++)
for (int j = i; j >= 1; j--)
boolean breaker = true;
if (ar[j] < ar[j - 1])
breaker = false;
swap(ar, j - 1, j);
if (breaker) break;
public static void main(String[] args) throws ExecutionException, InterruptedException
ThreadedSortingComparsion s = new ThreadedSortingComparsion();
s.start();
编辑:
当我在 Ideone 中运行它时,代码运行良好。
http://ideone.com/1E8C51
ideone有java版本1.8.0_51
我在1.8.0_91
、1.8.0_92
上进行了测试。和1.8.0_45
。
为什么它可以在 ideone 上运行,但不能在我测试的其他 2 台 PC 上运行?
当我做线程转储时,而不是在调试中执行,然后我等待一段时间,打印线程转储后,也会打印结果。所以线程转储是在完成插入排序后完成的。
"C:\Program Files\Java\jdk1.8.0_45\bin\java" -Xmx8G -Xss1G -Didea.launcher.port=7533 "-Didea.launcher.bin.path=C:\Program Files (x86)\JetBrains\IntelliJ IDEA Community Edition 2016.1.3\bin" -Dfile.encoding=UTF-8 -classpath "C:\Program Files\Java\jdk1.8.0_45\jre\lib\charsets.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\deploy.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\access-bridge-64.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\cldrdata.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\dnsns.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\jaccess.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\jfxrt.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\localedata.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\nashorn.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\sunec.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\sunjce_provider.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\sunmscapi.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\sunpkcs11.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\ext\zipfs.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\javaws.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\jce.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\jfr.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\jfxswt.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\jsse.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\management-agent.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\plugin.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\resources.jar;C:\Program Files\Java\jdk1.8.0_45\jre\lib\rt.jar;C:\Users\Tomasz_Mielczarski\IdeaProjects\untitled\out\production\untitled;C:\Program Files (x86)\JetBrains\IntelliJ IDEA Community Edition 2016.1.3\lib\idea_rt.jar" com.intellij.rt.execution.application.AppMain ThreadedSortingComparsion
array size: 1000000
2016-07-15 13:45:22
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.45-b02 mixed mode):
"pool-1-thread-4" #15 prio=5 os_prio=0 tid=0x00000000696bd000 nid=0x560 runnable [0x00000002fffee000]
java.lang.Thread.State: RUNNABLE
at ThreadedSortingComparsion.mergeSort(ThreadedSortingComparsion.java:77)
at ThreadedSortingComparsion.mergeSort(ThreadedSortingComparsion.java:78)
at ThreadedSortingComparsion.mergeSort(ThreadedSortingComparsion.java:78)
at ThreadedSortingComparsion.mergeSort(ThreadedSortingComparsion.java:78)
at ThreadedSortingComparsion.mergeSort(ThreadedSortingComparsion.java:77)
at ThreadedSortingComparsion$$Lambda$5/81628611.sort(Unknown Source)
at ThreadedSortingComparsion.lambda$measureTime$0(ThreadedSortingComparsion.java:21)
at ThreadedSortingComparsion$$Lambda$2/1023892928.call(Unknown Source)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-3" #14 prio=5 os_prio=0 tid=0x00000000696bb800 nid=0x2634 runnable [0x00000002bffee000]
java.lang.Thread.State: RUNNABLE
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:123)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:126)
at ThreadedSortingComparsion.quickSort(ThreadedSortingComparsion.java:105)
at ThreadedSortingComparsion$$Lambda$4/1989780873.sort(Unknown Source)
at ThreadedSortingComparsion.lambda$measureTime$0(ThreadedSortingComparsion.java:21)
at ThreadedSortingComparsion$$Lambda$2/1023892928.call(Unknown Source)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-2" #13 prio=5 os_prio=0 tid=0x00000000696b7800 nid=0x1c70 waiting on condition [0x000000027ffef000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000719d72480> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-1" #12 prio=5 os_prio=0 tid=0x00000000696b6800 nid=0x478 runnable [0x000000023ffee000]
java.lang.Thread.State: RUNNABLE
at ThreadedSortingComparsion.bubbleSort(ThreadedSortingComparsion.java:139)
at ThreadedSortingComparsion$$Lambda$1/990368553.sort(Unknown Source)
at ThreadedSortingComparsion.lambda$measureTime$0(ThreadedSortingComparsion.java:21)
at ThreadedSortingComparsion$$Lambda$2/1023892928.call(Unknown Source)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
"Monitor Ctrl-Break" #11 daemon prio=5 os_prio=0 tid=0x0000000068d3d000 nid=0x2f3c runnable [0x00000001fffee000]
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:170)
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 <0x00000007156892b8> (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 <0x00000007156892b8> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(BufferedReader.java:389)
at com.intellij.rt.execution.application.AppMain$1.run(AppMain.java:93)
at java.lang.Thread.run(Thread.java:745)
"Service Thread" #10 daemon prio=9 os_prio=0 tid=0x0000000068c81000 nid=0x2d6c runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C1 CompilerThread3" #9 daemon prio=9 os_prio=2 tid=0x0000000068bea800 nid=0x1ad0 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread2" #8 daemon prio=9 os_prio=2 tid=0x0000000068be4000 nid=0x17d0 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x0000000068bdd800 nid=0x3238 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x0000000068bda000 nid=0x1824 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x0000000068bd8800 nid=0x910 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x0000000068bd7800 nid=0x31f8 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x0000000043229800 nid=0x2810 in Object.wait() [0x00000000fffee000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000719d707e0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
- locked <0x0000000719d707e0> (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=0x0000000043223000 nid=0xd48 in Object.wait() [0x00000000bffef000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000719d78370> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)
- locked <0x0000000719d78370> (a java.lang.ref.Reference$Lock)
"main" #1 prio=5 os_prio=0 tid=0x000000000311d800 nid=0x2ed0 waiting on condition [0x000000004311e000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000719d58fe0> (a java.util.concurrent.FutureTask)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
at java.util.concurrent.FutureTask.get(FutureTask.java:191)
at ThreadedSortingComparsion.start(ThreadedSortingComparsion.java:48)
at ThreadedSortingComparsion.main(ThreadedSortingComparsion.java:162)
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:497)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)
"VM Thread" os_prio=2 tid=0x0000000056348800 nid=0x2984 runnable
"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000043147000 nid=0x27e0 runnable
"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000043148800 nid=0x20b4 runnable
"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x000000004314a000 nid=0x1da4 runnable
"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x000000004314c000 nid=0x29e0 runnable
"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x000000004314e000 nid=0xa04 runnable
"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x0000000043150000 nid=0x14b8 runnable
"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x0000000043153800 nid=0xf00 runnable
"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x0000000043154800 nid=0x243c runnable
"VM Periodic Task Thread" os_prio=2 tid=0x0000000068c82000 nid=0x22d8 waiting on condition
JNI global references: 224
Heap
PSYoungGen total 76288K, used 13755K [0x0000000715580000, 0x000000071aa80000, 0x00000007c0000000)
eden space 65536K, 4% used [0x0000000715580000,0x0000000715874910,0x0000000719580000)
from space 10752K, 99% used [0x0000000719580000,0x0000000719ffa348,0x000000071a000000)
to space 10752K, 0% used [0x000000071a000000,0x000000071a000000,0x000000071aa80000)
ParOldGen total 175104K, used 33211K [0x00000005c0000000, 0x00000005cab00000, 0x0000000715580000)
object space 175104K, 18% used [0x00000005c0000000,0x00000005c206ed30,0x00000005cab00000)
Metaspace used 4277K, capacity 4790K, committed 4992K, reserved 1056768K
class space used 484K, capacity 535K, committed 640K, reserved 1048576K
quick sort: 355.579434803s
merge sort: 355.629940032s
insertion sort: 355.532578023s
【问题讨论】:
合并和快速排序线程没有理由进入休眠状态。即使您只有两个内核(或定义一个包含 2 个线程的池),您也必须等待气泡和插入完成,然后才能合并和快速启动,但它们的时间应该是预期的。运行程序时可能会出现 CPU 或内存使用高峰。您是否尝试过使用较小的阵列?还是在 main 中没有无限循环? 你好,在较小的数组上,这个程序就像多线程一样。但是输入 1m 它开始像这样。没有 while(true) 的主要结果是相同的。它使用了我的 cpu 的 12.5% - 14%(一个核心的 100%),同时它有 4 个固定线程池和 3 个其他任务正在等待完成。 似乎过载的 CPU 会产生意外的行为。也许在调试模式下不会发生这种情况的原因是因为在调试模式下读取操作和空闲进程与算术运算交错,这会影响 S.O 线程调度程序。这是一个有趣的研究课题。 您能否发布在您假定应用程序运行单线程时采取的线程转储? 所以所有线程都在那里,唯一的问题是为什么你会得到不同的输出。线程转储上的命令行表明您不是直接运行 ThreadedSortingComparsion,而是通过“com.intellij.rt.execution.application.AppMain”运行。在命令行上直接运行您的程序。 “java -cpTL;DR 消除计数循环中的安全点检查的 HotSpot JIT 优化开了个恶作剧。
这是一个非常有趣的问题:一个简单的 Java 测试揭示了 JVM 深处的一个重要问题。
没有立即出现线程转储的事实表明问题不在 Java 代码中,而是在某种程度上与 JVM 有关。线程转储打印在安全点。延迟意味着虚拟机无法在短时间内到达安全点。
背景
当没有 Java 线程在运行时,某些 VM 操作(GC、去优化、线程转储和some other)在 stop-the-world 暂停时执行。但是 Java 线程不能在任意点停止,它们只能在称为 安全点 的特定位置暂停。在 JIT 编译的代码中,安全点通常放置在方法出口和后向分支处,即循环内部。
安全点检查在性能方面相对便宜,但不是免费的。这就是 JIT 编译器尽可能减少安全点数量的原因。一种这样的优化是消除计数循环中的安全点检查,即具有已知迭代次数有限的整数计数器的循环。
验证理论
让我们回到我们的测试并检查是否及时到达安全点。
添加-XX:+SafepointTimeout -XX:SafepointTimeoutDelay=1000
JVM 选项。每当 VM 未能在 1000 毫秒内到达安全点时,这应该会打印一条调试消息。
# SafepointSynchronize::begin: Timeout detected:
# SafepointSynchronize::begin: Timed out while spinning to reach a safepoint.
# SafepointSynchronize::begin: Threads which did not reach the safepoint:
# "pool-1-thread-2" #12 prio=5 os_prio=0 tid=0x0000000019004800 nid=0x1480 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
# SafepointSynchronize::begin: (End of list)
是的,它打印出线程 pool-1-thread-2
无法在 1000 毫秒内停止。这是 Executor 池的第二个线程,应该运行insertionSort
算法。
insertionSort
有两个非常长的嵌套计数循环,看起来 JVM 已经消除了其中的安全点检查。因此,如果此方法在编译模式下运行,则 JVM 在方法完成之前无法停止它。如果在方法运行时请求了 stop-the-world 暂停,所有其他线程也将等待。
怎么办?
这个问题早已为人所知。这是相关的 JVM 错误:JDK-5014723。这不是一个高优先级的问题,因为该问题很少出现在实际应用中。
JDK 8u92 中出现了一个新的 JVM 标志来解决该问题。-XX:+UseCountedLoopSafepoints
将始终将安全点检查放在循环中。
另一种解决方案是通过修改循环内的计数器变量将长计数循环转换为通用循环。
例如如果您将if (breaker) break;
替换为if (breaker) j = 0;
,问题也会消失。
那为什么它在调试模式下工作呢?
当 JVM 在调试器开启的情况下启动时,一些 JIT 优化被禁用以使调试信息可用。在这种情况下,编译后的代码具有所有安全点检查。
【讨论】:
这个答案很好地解释了线程转储的延迟。 OP 观察到的输出呢?插入排序中的这种 JIT 优化是否会以某种方式阻止合并/快速排序线程取得进展?还是对 System.nanoTime() 有副作用? @PavelGrushetzky 在insertionSort
运行时请求安全点,包括quickSort
和mergeSort
在内的所有其他线程都会挂起等待insertionSort
完成。
@apangin 谢谢,我想我现在看到了整体顺序:所有线程开始 -> 一段时间后 JIT/OSR 启动并从插入排序中删除安全点 -> 由于 GC/deopt/ 而发生安全点等 -> 所有线程快速到达安全点,但插入排序线程需要完成两个循环 -> JVM 在插入排序完成后到达全局安全点 -> 然后其余线程可以继续。
@PavelGrushetzky 完全正确。
在您在 jug.ru 上进行了令人兴奋的演示之后,我才提出这个问题。不过,我似乎不能两次投票。安德烈,请继续在 *** 上进行演示和回答......因为您的视频出现了,所以您在我们的办公室中产生了一个“安全点” - 没有人整天工作,我们所做的就是观看您的视频并尝试复制内容.令人惊叹的工作!以上是关于java代码执行在没有断点和正常运行的调试中产生不同的结果。 ExecutorService 坏了吗?的主要内容,如果未能解决你的问题,请参考以下文章
TelemetryClient 在 Application Insights 中产生不一致的结果
NULLIF 在 Amazon Redshift 中产生不正确的输出?