From owner-freebsd-java@FreeBSD.ORG Mon Feb 11 22:15:45 2013 Return-Path: Delivered-To: freebsd-java@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by hub.freebsd.org (Postfix) with ESMTP id BCA51919 for ; Mon, 11 Feb 2013 22:15:45 +0000 (UTC) (envelope-from david@code.davidpcaldwell.com) Received: from mail-ie0-x231.google.com (ie-in-x0231.1e100.net [IPv6:2607:f8b0:4001:c03::231]) by mx1.freebsd.org (Postfix) with ESMTP id 92E03189 for ; Mon, 11 Feb 2013 22:15:45 +0000 (UTC) Received: by mail-ie0-f177.google.com with SMTP id 16so8429997iea.36 for ; Mon, 11 Feb 2013 14:15:45 -0800 (PST) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20120113; h=x-received:mime-version:x-originating-ip:from:date:message-id :subject:to:content-type:x-gm-message-state; bh=kMjvBhdoIhwKUMCZroUJTc6+EvsaJDYFiqMmPQbV7go=; b=aHxeLWyM5oOFgFxYTsNz02UkRJwwu5fn1VHrTXsNLoofLcMMFXB9yg9OHajWv8dsw/ j2Xy0CEOhLukLEV4k9pLZ+NpOKGQXBQPPWpAyhB7o2M7jYroi7GMU2Ly74+tQXMpnQcE hVksOAB0LmJ2+Uu6u6IcN2T37AjB1zkAxz4PNpjU7wt3nHsAAUIrXEfJzQ/GKV3OdT7B Y6I/q3wugYPF4WOOxtea76eOcMrsGkCyD08sRehla/6Awbm5viHOijWcOBXyC0cGNDmr LEH4UDQTIeqxFFQ9Yc5L1hvxknzZ49CVVHF3rVDiGqFkgRdryu3nGGzeoN/I5EOigDX3 L7Aw== X-Received: by 10.50.40.129 with SMTP id x1mr14346069igk.54.1360620944981; Mon, 11 Feb 2013 14:15:44 -0800 (PST) MIME-Version: 1.0 Received: by 10.64.134.198 with HTTP; Mon, 11 Feb 2013 14:15:23 -0800 (PST) X-Originating-IP: [74.97.25.177] From: "David P. Caldwell" Date: Mon, 11 Feb 2013 17:15:23 -0500 Message-ID: Subject: Problem with Java System.exit on OpenJDK 7 To: freebsd-java@freebsd.org X-Gm-Message-State: ALoCoQl13HyuX9UKNoGLS/VQdJYYpofY0wN8Q9X72w6bhnJR4z7TvEsp/DNGRAOKlZ2D9oF2DYem Content-Type: text/plain; charset=ISO-8859-1 X-Content-Filtered-By: Mailman/MimeDel 2.1.14 X-BeenThere: freebsd-java@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Porting Java to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 11 Feb 2013 22:15:45 -0000 So I'm having a problem with the performance of a Java subprocess running under Java, running on 9.0-RELEASE i386. It's a big subprocess, difficult to decompose. It's a big parent process, difficult to decompose. I'm working on it. I've nearly ruled out the parent process as the culprit (see below), but I include it for completeness, just in case there's something I'm missing. Everything runs as expected on Windows, which brings me here to this list. Basically, the parent process launches the subprocess using a Java command. It runs. It runs fine. The *subprocess* calls System.exit(0). That's where the weirdness begins. System.exit(), for this program, takes about 2.6 seconds to run. And I can't figure out why. It takes 0.025 seconds on Windows. The program is a command shell, essentially, so having every subshell add 2.6 seconds of unnecessary execution time really slows things down. 1. The application has System.runFinalizersOnExit set to false; I checked in java.lang.Shutdown using reflection to be sure. 2. The application, during its shutdown, has only one shutdown hook to run -- the application shutdown hooks hook. That application shutdown hooks hook has one hook, registered by me, which prints the timestamp (for trying to debug this), only. Something takes 2.6 seconds to end the VM after this. 3. There are no temporary files to delete; I checked in java.io.DeleteFilesOnExit using reflection to make sure. The system registered shutdown hook in the slot for DeleteFilesOnExit is null. The problem appears to have nothing to do with the parent process. I synthesized a giant command line command using the environment variables and system properties under which the subprocess is running, and ran it from the bash prompt, and still got the 2.6 second delay, based on running the program inside a bash wrapper that first ran the subprocess giant command, then printed the system time. I'm 99.9% ready to rule it out based on that. During one experiment, when running the program twice on the same command line, one of the runs, using the same command line, actually completed System.exit in a time I'd expect -- about 0.03 seconds. The other took about 2.6 seconds. All subsequent runs have take about two-and-a-half seconds after the shutdown hooks; I haven't been able to reproduce the success and I am quite sure I didn't change anything. I'm running this in a graphical terminal on KDE; haven't tried from an ordinary console (obviously I am gradually broadening the things I'm doing, so I'll probably get to that). The program is not graphical and presents no GUI. The application does reference the standard input stream but the particular program I was running consumes no input. It references stdout and stderr as well, and is emitting output to those consoles. Does anyone have any idea or suggestions about where I should be looking at this point? Obviously it's hard to instrument the program further on FreeBSD -- I assume the NetBeans Profiler / jvisualvm stuff does not work on FreeBSD; that's the last I heard.