Initial feedback from Apache Ant users on recent security manager warning messages

[Jaikiran Pai]

(resending from the correct subscribed address)

Given the recent changes around the Java SecurityManager deprecation, 
the Ant project has been asking for user feedback on how this change 
impacts them with their Ant build files/tasks. So far we have received 
two separate user reports around this. Both of them come down to the 
same issue. Before getting to that, let me provide some context around 
what Ant does with SecurityManager. I wasn't around when the intial 
design and discussions happened decades back on Ant's usage of Java 
SecurityManager, so my knowledge around this mostly based on what I see 
in the Ant project's code and its documentation.

Ant allows user defined builds to define (optional) permissions[2]. As 
you can see from that documentation, it's just a wrapper on top of what 
Java SecurityManager provides. We internally just set up the Java 
SecurityManager appropriately and invoke the relevant tasks.

Of course, "permissions" are optional and I am not sure how many of our 
users use any of them. However, there are some tasks in Ant, like the 
"java" task which by default apply certain permissions before launching 
these tasks. The internal implementation of the "java" task sets a 
custom security manager which overrides the checkPermission(...) API to 
match against the default permissions that are set for this task. All 
that code resides in the Permissions class (and its nested MySM class) 
here[3].

Many Ant tasks run within the same JVM as the one in which the Ant build 
has been triggered. Users are allowed to configure their builds to 
launch these tasks in a "forked" (separate) JVM. "java" is one such 
task. By default we do _not_ fork and instead launch the user configured 
class in the same VM as that of the Ant build. As noted earlier, when we 
do this, we first set a new security manager and then once the execution 
completes, reset the security manager back to the old one. The setting 
and resetting of the security manager happens using the 
System.setSecurityManager(...) API, from within the same (Ant project's 
internal Permissions.java) class.


With that background, let me now get to the issue that has been reported 
by more than one user. Up until these recent EA releases of Java 17, 
users who had Ant build files (some of them very large with many 
targets/tasks) had numerous build targets and many of these targets have 
the "java" task. And since this task by default doesn't fork, most of 
these build files aren't forking when this build target is executed. 
Starting these releases, these users have started to see a flood of the 
deprecation warning messages, due to Ant's (internal) calls to 
System.setSecurityManager(...).


Consider this simple Ant build file and a trivial Java program:

<project default="helloworld">

     <target name="compile">
         <javac srcdir="." destdir="."/>
     </target>

     <target name="helloworld" depends="compile" description="Launch 
Java program to say hello world">
         <java classname="HelloWorld" classpath="."/>

     </target>

</project>

public class HelloWorld {

     public static void main(final String[] args) throws Exception {
         System.out.println("Hello world");
     }
}

All it does is, in its "helloworld" target, uses one single "java" task 
to launch the HelloWorld class. The output it generates (I use the term 
output loosely and don't really mean STDOUT but a combination of STDOUT 
and STDERR content that gets printed out) is as follows (this is against 
latest Java 17 build 17-ea+28-2534):


helloworld:
WARNING: A terminally deprecated method in java.lang.System has been called
WARNING: System::setSecurityManager has been called by 
org.apache.tools.ant.types.Permissions 
(file:/home/me//apache-ant-1.10.9/lib/ant.jar)
WARNING: Please consider reporting this to the maintainers of 
org.apache.tools.ant.types.Permissions
WARNING: System::setSecurityManager will be removed in a future release
      [java] Hello world
WARNING: A terminally deprecated method in java.lang.System has been called
WARNING: System::setSecurityManager has been called by 
org.apache.tools.ant.types.Permissions 
(file:/home/me//apache-ant-1.10.9/lib/ant.jar)
WARNING: Please consider reporting this to the maintainers of 
org.apache.tools.ant.types.Permissions
WARNING: System::setSecurityManager will be removed in a future release

There are multiple things of note here:

1. For a single line of output from the program it ended up generating 8 
additional lines of warning messages. I know this is a visual thing, but 
I wanted to highlight what I (and the users who reported this) meant by 
"flooding" of the logs. This virtually makes it almost impossible to 
find any real output from the program when someone is viewing the logs.

2. Notice that although it's the same 
org.apache.tools.ant.types.Permissions which is the caller to the 
System.setSecurityManager(...) API, it's being reported more than once. 
I want to emphasize this part too, since although you see it twice here, 
the important bit to remember is, it gets printed twice for every single 
usage of "java" task in the build file. So the more number of "java" 
tasks, the more you will see these messages pointing to the same culprit 
org.apache.tools.ant.types.Permissions class. For example, just add 
another "java" task in that sample build file and you will 16 lines of 
warning messages with the exact same content as above for just 2 lines 
of output from the program. IMO, repeating this log message more than 
once for the same caller class adds no value. After all, being notified 
that the specific class is using setSecurityManager at least once should 
be enough to have that class reviewed for the usage of this method.

3. This is something I raised in a separate discussion thread a few 
weeks back. In the above warning message, it's good to see that the 
caller class is being printed. However, in the above case I still 
have/had no clue why the
org.apache.tools.ant.types.Permissions was being reported twice. It's 
only when I went back to the *source code* (I emphasize this part for 
the sake of my next point) that I realized that it's being reported 
twice because of the set new security manager and reset back to old 
security manager using the setSecurityManager calls in the Permissions 
class. Again this is a guess and in this case an accurate one. What 
would have helped (and will still help) is a way to "debug" this 
immediately instead of having of open an IDE and then review the code 
(I'm probably exaggerating this part, since it's just a matter of 
searching for setSecurityManager calls in that class). If I could 
somehow set some property and see a stacktrace of these calls, it 
wouldn't have been an initial surprise to see 2 warning messages coming 
from the Permissions class for a single invocation of the "java" task.

4. In that log message, like I noted in one of the recent PR review 
comments, I think printing the codesource (jar file location on the 
filesystem) of the class which calls the API isn't adding any value. 
Personally, if/when I see this warning message and want to look into why 
it's being reported, I don't go to a jar file containing compiled 
binaries. Instead, once I know the caller class (the one reported in 
that log message), I try and find its source code to see what's going 
on. I don't remember using a decompiler the past couple of years for 
debugging issues like these, so I am not too sure that codesource 
location of the class file is adding any value.


Out of all these 4 points, I think if point number 2 can be addressed 
such that it just prints only once the warning for each caller class, 
then the issue noted by users of Ant build file will be drastically 
reduced. I haven't yet tried or proved it, but I think we will end up 
with just one log message in their STDERR for the entire build for a 
majority of the cases. I will experiment with that this week to see if 
that's true.

Of course, none of this is a solution to Ant's usage of SecurityManager. 
We (Ant project) will still have to review and remove these usages 
(which will impact the users) but that's a given. What's become a bit 
painful right now for users is that although in practice nothing has 
changed (i.e. SecurityManager behaves just like it does today and will 
continue to do so in Java 17), yet all their builds are impacted or will 
be by the deluge of these warning messages which they have no control 
over (even when they don't care or use security manager). I would expect 
that a lot of the users would want to move to Java 17 given its expected 
support life, but I think these warning messages are going to be hard to 
manage or deal with.

On a slightly related note, I was wondering why we decided to go with 
what appears to be a bit more aggressive approach to these warning 
messages as compared to what was done with the illegal reflective access 
warnings? I would have thought that the illegal reflective access 
changes would be much more involved if not the same level as moving away 
from setSecurityManager calls. Yet, those log messages weren't these 
intrusive and I hadn't seen anyone complaining about those message 
interfering with their program output or flooding their logs. In fact, I 
just gave it a try today against a slightly lenient JDK 15 with the 
following code:

public class HelloWorld {

     public static void main(final String[] args) throws Exception {
         java.lang.reflect.Method m = 
System.class.getDeclaredMethod("checkIO");
         m.setAccessible(true);


         java.lang.reflect.Method m2 = 
java.util.ArrayList.class.getDeclaredMethod("grow");
         m2.setAccessible(true);

     }
}

Notice that it does 2 illegal reflective accesses and when I run this 
(against Java 15) I get:

WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by HelloWorld (file:HelloWorld.java) 
to method java.lang.System.checkIO()
WARNING: Please consider reporting this to the maintainers of HelloWorld
WARNING: Use --illegal-access=warn to enable warnings of further illegal 
reflective access operations
WARNING: All illegal access operations will be denied in a future release

So it reports only the first access by default and no more, which 
probably explains why not many users complained about these log 
messages. Of course, library owners and application server providers all 
enabled the additional flags like "warn", "debug" to get more details 
and fix their code. Why not the same or something similar with the 
setSecurityManager calls?


[1] https://www.mail-archive.com/user@ant.apache.org/msg43019.html
[2] http://ant.apache.org/manual/Types/permissions.html
[3] 
https://github.com/apache/ant/blob/master/src/main/org/apache/tools/ant/types/Permissions.java 


-Jaikiran


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/security-dev/attachments/20210628/a265c95a/attachment.htm>