"statistics unavailable at this time" when trying to print String Pool information?

Question

I am following a udemy course on java performance management and I am coming across an issue that is preventing me from printing out information for the String pool. This is what I get when I attempt to add ten million String objects to the pool:

E:\IntelliJ Projects\ExploringStrings\src>java -XX:+PrintStringTableStatistics Main
Elapsed time was 28311 ms.
SymbolTable statistics:
Number of buckets       :     20011 =    160088 bytes, each 8
Number of entries       :     20527 =    492648 bytes, each 24
Number of literals      :     20527 =    776904 bytes, avg  37.848
Total footprint         :           =   1429640 bytes
Average bucket size     :     1.026
Variance of bucket size :     1.033
Std. dev. of bucket size:     1.017
Maximum bucket size     :         9
statistics unavailable at this moment

This is what I get when I run the program with an empty main method:

E:\IntelliJ Projects\ExploringStrings\src>java -XX:+PrintStringTableStatistics Main
SymbolTable statistics:
Number of buckets       :     20011 =    160088 bytes, each 8
Number of entries       :     16615 =    398760 bytes, each 24
Number of literals      :     16615 =    608976 bytes, avg  36.652
Total footprint         :           =   1167824 bytes
Average bucket size     :     0.830
Variance of bucket size :     0.837
Std. dev. of bucket size:     0.915
Maximum bucket size     :         9
StringTable statistics:
Number of buckets       :     65536 =    524288 bytes, each 8
Number of entries       :      1734 =     27744 bytes, each 16
Number of literals      :      1734 =    112456 bytes, avg  64.854
Total footprsize_t         :           =    664488 bytes
Average bucket size     :     0.026
Variance of bucket size :     0.027
Std. dev. of bucket size:     0.163
Maximum bucket size     :         2

This is the code that attempts to add 10 million Strings to the pool:

import java.util.ArrayList;
import java.util.Date;
import java.util.List;

public class Main {

    public static void main(String[] args) {

        Date start = new Date();

        List<String> strings = new ArrayList<String>();

        for(Integer i = 1; i < 10000000; i++) {
            String s =  i.toString().intern(); //Adds new string object to the string pool
            strings.add(s);
        }

        Date end = new Date();
        System.out.println("Elapsed time was " + (end.getTime() - start.getTime()) + " ms.");

    }
}

So, my question is: Why can't I print out information for the String pool when I attempt to add 10 million objects, but my instructor can? I am failing to understand the reasoning as this is pretty beyond my level of Java programming. Thank you all.

Answer 1

tl;dr

Wait a few seconds before exiting, to avoid "statistics unavailable at this moment" issue.

Thread.sleep( Duration.ofSeconds( 5 ).toMillis() )

Details

If you are referring to that message on the console:

statistics unavailable at this moment

… I experienced the same with code similar to yours.

package work.basil.example;

import java.time.Duration;
import java.time.Instant;
import java.util.ArrayList;
import java.util.List;

public class Stringer
{
    public static void main ( String[] args )
    {
        Instant start = Instant.now();
        System.out.println( "Starting run at:" + start + ". Runtime.version(): " + Runtime.version() );
        List < String > strings = new ArrayList < String >();

        for ( int i = 1 ; i < 10_000_000 ; i++ )
        {
            String s = String.valueOf( i ).intern();  // Adds new string object to the string pool.
            strings.add( s );
        }

        System.out.println( "Elapsed time was " + Duration.between( start , Instant.now() ) );
    }
}

When run on macOS Mojave on Intel with Java 15 from AdoptOpenJDK, executed within IntelliJ 2020.3.1.

/Library/Java/JavaVirtualMachines/adoptopenjdk-15.jdk/Contents/Home/bin/java -XX:+PrintStringTableStatistics --enable-preview -javaagent:/Users/basilbourque/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/203.6682.168/IntelliJ IDEA 2020.3 EAP.app/Contents/lib/idea_rt.jar=52178:/Users/basilbourque/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/203.6682.168/IntelliJ IDEA 2020.3 EAP.app/Contents/bin -Dfile.encoding=UTF-8 -classpath /Users/basilbourque/IdeaProjects/ExampleJava/target/classes:/Users/basilbourque/.m2/repository/com/h2database/h2/1.4.200/h2-1.4.200.jar:/Users/basilbourque/.m2/repository/com/thedeanda/lorem/2.1/lorem-2.1.jar:/Users/basilbourque/.m2/repository/org/postgresql/postgresql/42.2.18/postgresql-42.2.18.jar:/Users/basilbourque/.m2/repository/org/checkerframework/checker-qual/3.5.0/checker-qual-3.5.0.jar:/Users/basilbourque/.m2/repository/org/apache/commons/commons-csv/1.8/commons-csv-1.8.jar work.basil.example.Stringer
Starting run at:2021-01-04T02:03:34.484633Z. Runtime.version(): 15.0.1+9
Elapsed time was PT6.219106S
SymbolTable statistics:
Number of buckets       :     32768 =    262144 bytes, each 8
Number of entries       :      2633 =     42128 bytes, each 16
Number of literals      :      2633 =     98200 bytes, avg  37.000
Total footprint         :           =    402472 bytes
Average bucket size     :     0.080
Variance of bucket size :     0.079
Std. dev. of bucket size:     0.280
Maximum bucket size     :         2
statistics unavailable at this moment

Process finished with exit code 0

…where I get the same statistics unavailable at this moment message.

So on a wild guess, I added a Thread.sleep call to wait 5 seconds before exiting.

try { Thread.sleep( Duration.ofSeconds( 5 ).toMillis() ); } catch ( InterruptedException e ) { e.printStackTrace(); }

So, in running this:

package work.basil.example;

import java.time.Duration;
import java.time.Instant;
import java.util.ArrayList;
import java.util.List;

public class Stringer
{
    public static void main ( String[] args )
    {
        Instant start = Instant.now();
        System.out.println( "Starting run at:" + start + ". Runtime.version(): " + Runtime.version() );
        List < String > strings = new ArrayList < String >();

        for ( int i = 1 ; i < 10_000_000 ; i++ )
        {
            String s = String.valueOf( i ).intern();  // Adds new string object to the string pool.
            strings.add( s );
        }

        System.out.println( "Elapsed time was " + Duration.between( start , Instant.now() ) );
        try { Thread.sleep( Duration.ofSeconds( 5 ).toMillis() ); } catch ( InterruptedException e ) { e.printStackTrace(); }
    }
}

I get this:

/Library/Java/JavaVirtualMachines/adoptopenjdk-15.jdk/Contents/Home/bin/java -XX:+PrintStringTableStatistics --enable-preview -javaagent:/Users/basilbourque/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/203.6682.168/IntelliJ IDEA 2020.3 EAP.app/Contents/lib/idea_rt.jar=52114:/Users/basilbourque/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/203.6682.168/IntelliJ IDEA 2020.3 EAP.app/Contents/bin -Dfile.encoding=UTF-8 -classpath /Users/basilbourque/IdeaProjects/ExampleJava/target/classes:/Users/basilbourque/.m2/repository/com/h2database/h2/1.4.200/h2-1.4.200.jar:/Users/basilbourque/.m2/repository/com/thedeanda/lorem/2.1/lorem-2.1.jar:/Users/basilbourque/.m2/repository/org/postgresql/postgresql/42.2.18/postgresql-42.2.18.jar:/Users/basilbourque/.m2/repository/org/checkerframework/checker-qual/3.5.0/checker-qual-3.5.0.jar:/Users/basilbourque/.m2/repository/org/apache/commons/commons-csv/1.8/commons-csv-1.8.jar work.basil.example.Stringer
Starting run at:2021-01-04T02:02:21.792377Z. Runtime.version(): 15.0.1+9
Elapsed time was PT5.887848S
SymbolTable statistics:
Number of buckets       :     32768 =    262144 bytes, each 8
Number of entries       :      2635 =     42160 bytes, each 16
Number of literals      :      2635 =     98280 bytes, avg  37.000
Total footprint         :           =    402584 bytes
Average bucket size     :     0.080
Variance of bucket size :     0.079
Std. dev. of bucket size:     0.281
Maximum bucket size     :         2
StringTable statistics:
Number of buckets       :   8388608 =  67108864 bytes, each 8
Number of entries       :  10000880 = 160014080 bytes, each 16
Number of literals      :  10000880 = 480062480 bytes, avg  48.000
Total footprint         :           = 707185424 bytes
Average bucket size     :     1.192
Variance of bucket size :     1.383
Std. dev. of bucket size:     1.176
Maximum bucket size     :         9

Process finished with exit code 0

After waiting to exit, the statistics unavailable at this moment message is gone, and we get full statistics.

We do indeed see Number of literals jump from a few thousand to over ten million. Presumably this is due to our loop of ten million numbers turned into strings.

Documentation?

I tried to research this, to learn the documented behavior of the PrintStringTableStatistics switch. But I cannot find any documentation. I have no idea where to find documentation nowadays for the console tools java, javac, and so on.

If anyone has a link, please post.

Answer 2

As an addendum, that line simply says that some thread that wants to request statistics could not acquire the lock, as seen here.

The method that is trying to be called (try_resize_lock) is here. It surely looks like the thread that requested the statistics could not acquire a certain lock (I guess, it's because some other thread was updating the ConcurrentHashTable in that exact moment).

I have not looked at the exact details and implementation of why this thread can no simply wait until it could get the lock (like synchronized does), but I guess there are compelling reasons that I am not aware of.