topic Re: Subprocess hangs if created by Java in Operating System - OpenVMS

Subprocess hangs if created by Java

Dominik Andelshauser — Fri, 30 Sep 2005 08:47:17 GMT

I run into a problem that really confuse me. I'm not sure whether this is the right forum. But I was introduced to write it here.

Hava a look at the following Java-Code (this part is working as expected; the problem is explained later):

** E.java *************************************
import java.lang.*;

public class E {
public static void main(String args[]) {
E e = new E();
}
public E() {
MyThread thread = new MyThread();
}
public class MyThread extends Thread {
public MyThread() {
start();
}
public void run() {
int ExitCode=0;
try {
System.out.println("Executing TEST");
Process p = Runtime.getRuntime().exec("SYS$LOGIN:test.exe");
System.out.println("exec executed");
ExitCode = p.waitFor();
System.out.println("Exitcode = " + ExitCode);
}
catch (Exception e) {
System.out.println(
"Error: Could not launch TEST. Error Message is:"
+ e.getMessage());
}
}
}
}

** test.c *********************************
#include

int main(int argc, char *argv[])
{
FILE *fo = fopen("x.x", "w");
int i;

for (i = 0; i < argc; i++)
fprintf(fo, "%s\n", argv[i]);
fclose(fo);

return 0;
}
*******************************************

Compiling and starting java returns the following output:
$ java E
Executing TEST
exec executed
Exitcode = 1
$
and the file x.x is being created by the called subprocess test.exe.

Problem detail:

If I put the above Java-code into a Java project with some more threads and lot of selfwritten java-classes, the only output is "Executing TEST". That means the call to exec() never returns. This threads hangs in state "$waitfr 62". This seems to be due to the implicit call to lib$spawn from Java.
The subprocess to be started (test.exe) also is in state "LEF". The process did not even enter the main()-function: no file has been created and the system analyzer returns only return-addresses to shared libraries (show call | show call/next).

I am really confused. Can anyone help me, please?

Greetings
Dominik

Re: Subprocess hangs if created by Java

Ian Miller. — Fri, 30 Sep 2005 09:55:27 GMT

Are there any active channels shown in SDA?
(LIB$SPAWN uses mailboxes to pass context information).

Do you know which event flag the subprocess is waiting for?

Re: Subprocess hangs if created by Java

Dominik Andelshauser — Fri, 30 Sep 2005 10:31:45 GMT

there are channels open for
DCL.EXE, DCLTABLES.EXE, RTA2:, MBA7278: and MBA7275:
the last is in state busy
show device MBA7275 says that the "I/O request queue is empty"

both mailbox devices are connected to the parent process, too (no status)

I am not sure how to find out for which event flag the subprocess is waiting. The only thing I found was the following lines:

Local event flag cluster 0 C0000001
Local event flag cluster 1 00000000
(the same values as shown with show/proc/cont/id=xx on the command line)

Dominik

Re: Subprocess hangs if created by Java

Ian Miller. — Mon, 03 Oct 2005 03:40:38 GMT

Look at waiting event flag cluster and waiting event flag mask. The clear bits in the event flag wait mask are the event flags you are waiting for and the EF cluster number tells you which set of 32 flags.

e.g
Waiting EF cluster 1 Event flag wait mask BFFFFFFF

is event flag 30 in the 2nd cluster i.e 62

Re: Subprocess hangs if created by Java

Dominik Andelshauser — Mon, 03 Oct 2005 08:49:39 GMT

Sorry for the late response, there is a bank-holiday today here in Germany.

I found the following entry:

Waiting EF cluster 4 Event flag wait mask 00000000

this means the process is waiting on all event flags 128 to 191 !? I thought there are at most 64 event flags.

By the way, we are using OpenVMS 7.3-2 and Java Fast VM (build 1.4.2-4.p2, build J2SDK.v.1.4.2:05/09/2005-13:09, native threads, jit_142)

The whole output of SDA:

SDA> show proc/id=20202ACC

Process index: 004C Name: ANDELSHAUSE_250 Extended PID: 20202ACC
--------------------------------------------------------------------
Process status: 02040001 RES,PHDRES,INTER
status2: 00000000

PCB address 81B15AC0 JIB address 816960C0
PHD address 83B1C000 Swapfile disk address 00000000
KTB vector address 81B15DAC HWPCB address FFFFFFFF.83B1C080
Callback vector address 00000000 Termination mailbox 1F42
Master internal PID 004C004B Subprocess count 0
Creator extended PID 2020264B Creator internal PID 004C004B
Previous CPU Id 00000001 Current CPU Id 00000001
Previous ASNSEQ 000000000006C668 Previous ASN 0000000000000094
Initial process priority 4 # open files remaining 4069/4096
Delete pending count 0 Direct I/O count/limit 300/300
UIC [00002,000014] Buffered I/O count/limit 299/300
Abs time of last event 251B8A46 BUFIO byte count/limit 3952320/3952320
# of threads 1 ASTs remaining 497/500
Swapped copy of LEFC0 00000000 Timer entries remaining 99/100
Swapped copy of LEFC1 00000000 Active page table count 0
Global cluster 2 pointer 00000000 Process WS page count 94
Global cluster 3 pointer 00000000 Global WS page count 1
PCB Specific Spinlock 81B28000 Subprocesses in job 1

Thread index: 0000
------------------
Current capabilities: System: 0000000C QUORUM,RUN
User: 00000000
Permanent capabilities: System: 0000000C QUORUM,RUN
User: 00000000
Current affinities: 00000000
Permanent affinities: 00000000
Thread status: 02040001
status2: 00000000

KTB address 81B15AC0 HWPCB address FFFFFFFF.83B1C080
PKTA address 7FFEFF98 Callback vector address 00000000
Internal PID 0055004C Callback error 00000000
Extended PID 20202ACC Current CPU id 00000001
State LEF Flags 00000000
Base priority 4 Current priority 9
Waiting EF cluster 4 Event flag wait mask 00000000
CPU since last quantum 01CC Mutex count 0
ASTs active NONE

Re: Subprocess hangs if created by Java

Ian Miller. — Mon, 03 Oct 2005 09:26:17 GMT

that process is waiting for the event flag number 128. This event flag does not actually exist but you can use it! (If event flag wait cluster is 4 then event flag wait mask is not used)

Event flag 128 was invented to be used when you don't want an event flag but the system service needs on or you need a thread local event flag.
See
http://h71000.www7.hp.com/doc/73final/5841/5841pro_020.html#enf_lef

Re: Subprocess hangs if created by Java

Dominik Andelshauser — Mon, 03 Oct 2005 10:06:05 GMT

Ok, that was the thing with the event flag.
But I still wonder why the call to exec() (lib$spawn) never returns, i.e. why the subprocess never starts.
Is it possible that the main process blocks any resources that the new process to be created needs? And which resouces are they? How can I find it out?

Re: Subprocess hangs if created by Java

Ian Miller. — Mon, 03 Oct 2005 10:44:55 GMT

can you post the call stack
SHOW CALL
SHOW CALL/NEXT
SHOW CALL/NEXT
etc

It appears you have not run out of any quota, have one buffered I/O waiting and one timer.

The process you give the output for was the subprocess and it appears to be waiting for EF 128. The main process is waiting for EF 62 - is that correct?

Re: Subprocess hangs if created by Java

Dominik Andelshauser — Mon, 03 Oct 2005 11:15:32 GMT

The buffered IO waiting seems to be on a mailbox device as mentioned above.
It is correct what you said last.

here comes the output of show call(/next) of the subprocess.
Do not wonder that the PID has changed.

Dominik

SDA> set proc/id=20202BD6
SDA> show call

Call Frame at 00000000.7FF9DC00
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: FFFFFFFF.8015A8A0 PROCESS_MANAGEMENT+348A0
Return address on stack = FFFFFFFF.80577290 RMS+47290

Registers saved on stack
------------------------
7FF9DC40 00000000.7AF42050 Saved R13
7FF9DC48 00000000.7FF9DC50 Saved R29

SDA> show call/next

Call Frame at 00000000.7FF9DC50
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: FFFFFFFF.80577200 RMS+47200
Return address on stack = FFFFFFFF.80578268 RMS+48268

Registers saved on stack
------------------------
7FF9DC70 FFFFFFFF.811B8410 Saved R2 RMS$MOUNT+003D0
7FF9DC78 00000000.0000000F Saved R3
7FF9DC80 00000000.7FFCEFB0 Saved R4
7FF9DC88 00000000.7FF9DC90 Saved R29

SDA> show call/next

Call Frame at 00000000.7FF9DC90
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: FFFFFFFF.805781D0 RMS+481D0
Return address on stack = 00000000.7AFA0D64

Registers saved on stack
------------------------
7FF9DCB0 00000000.7FF9FEB6 Saved R2
7FF9DCB8 00000000.7FF9DE00 Saved R29

SDA> show call/next

Call Frame at 00000000.7FF9DE00
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: 00000000.7AF7C100
Handler at 00000000.7AF3D270
Return address on stack = FFFFFFFF.80170C24 AMAC$EMUL_CALL_NATIVE_C+00084

Registers saved on stack
------------------------
7FF9DE18 00000000.0000000B Saved R2
7FF9DE20 FFFFFFFF.810C6380 Saved R3 EXCEPTION+43180
7FF9DE28 FFFFFFFF.816FA080 Saved R4 PCB
7FF9DE30 00000000.00000088 Saved R5
7FF9DE38 00000000.00041B04 Saved R6
7FF9DE40 00000000.7FF8BFC0 Saved R7
7FF9DE48 00000000.7FFA4F30 Saved R8
7FF9DE50 00000000.7FFABFC0 Saved R9
7FF9DE58 00000000.00000000 Saved R10
7FF9DE60 00000000.7FF1A1B2 Saved R11

Press RETURN for more.
SDA>

Call Frame at 00000000.7FF9DE00
-------------------------------
7FF9DE68 00000000.7AF3D248 Saved R13
7FF9DE70 00000000.7FFD0620 Saved R15 CTL$GL_IAFEXE
7FF9DE78 00000000.7FFABFC0 Saved R29

SDA> show call/next

Call Frame at 00000000.7FFABFC0
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: 00000000.7AF7C060
Return address on stack = FFFFFFFF.80170C24 AMAC$EMUL_CALL_NATIVE_C+00084

Registers saved on stack
------------------------
7FFABFD0 00000000.00000000 Saved R8
7FFABFD8 FFFFFFFF.81012620 Saved R9 SYS$GB_CALLOUTS
7FFABFE0 00000000.7AF3D200 Saved R13
7FFABFE8 00000000.00000000 Saved R29

SDA> show call/next
%SDA-E-NOTINPHYS, 00000000.00000000 : virtual data not in physical memory
SDA>

Re: Subprocess hangs if created by Java

Ian Miller. — Mon, 03 Oct 2005 11:52:38 GMT

Has you done
READ/EXEC
READ SDA$READDIR:SYSDEF

in SDA before those SHOW CALL commands?

Re: Subprocess hangs if created by Java

Dominik Andelshauser — Wed, 05 Oct 2005 02:17:47 GMT

Does this help you?

SDA> read/exec
%SDA-I-READSYM, 739 symbols read from SYS$COMMON:[SYS$LDR]SYS$RMDRIVER.STB;1
%SDA-I-READSYM, 1 symbols read from SYS$COMMON:[SYS$LDR]SYS$LTDRIVER.EXE;1
%SDA-I-READSYM, 1 symbols read from SYS$COMMON:[SYS$LDR]LAT$RATING.EXE;1
%SDA-W-OPENIN, error opening SDA$READ_DIR:PWIPDRIVER as input
-RMS-W-FNF, file not found
%SDA-I-READSYM, 1 symbols read from SYS$COMMON:[SYS$LDR]TCPIP$PROXY_SERVICES.EXE;1
%SDA-I-READSYM, 1 symbols read from SYS$COMMON:[SYS$LDR]TCPIP$TNDRIVER.EXE;1
%SDA-I-READSYM, 1 symbols read from SYS$COMMON:[SYS$LDR]TCPIP$INTERNET_SERVICES.EXE;1
...
%SDA-I-READSYM, 645 symbols read from SYS$COMMON:[SYS$LDR]X25$NWDRIVER.STB;1
%SDA-W-LINKTIMEMISM, link time of SYS$COMMON:[SYS$LDR]X25$NWDRIVER.STB;1 (24-MAY-2001 17:57) does not match link time of image in system (27-JUL-2001 16:49)
%SDA-I-READSYM, 245 symbols read from SYS$COMMON:[SYS$LDR]X25$XOT.STB;1
%SDA-I-READSYM, 167 symbols read from SYS$COMMON:[SYS$LDR]X25$RELAY.STB;1
...

SDA> read SDA$READDIR:SYSDEF
%SDA-W-OPENIN, error opening SDA$READDIR:SYSDEF as input
-RMS-W-DEV, error in device name or inappropriate device type for operation
SDA> set proc/id=20202CB0
SDA> show call

Call Frame at 00000000.7FF9DC00
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: FFFFFFFF.8015A8A0 SYS$SYNCH_C
Return address on stack = FFFFFFFF.80577290 RMS+47290

Registers saved on stack
------------------------
7FF9DC40 00000000.7AF42050 Saved R13
7FF9DC48 00000000.7FF9DC50 Saved R29

SDA> show call/next

Call Frame at 00000000.7FF9DC50
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: FFFFFFFF.80577200 RMS+47200
Return address on stack = FFFFFFFF.80578268 SYS$PUT_C+00098

Registers saved on stack
------------------------
7FF9DC70 FFFFFFFF.811B8410 Saved R2 SYS$PUT
7FF9DC78 00000000.0000000F Saved R3
7FF9DC80 00000000.7FFCEFB0 Saved R4
7FF9DC88 00000000.7FF9DC90 Saved R29

SDA> show call/next

Call Frame at 00000000.7FF9DC90
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: FFFFFFFF.805781D0 SYS$PUT_C
Return address on stack = 00000000.7AFA0D64

Registers saved on stack
------------------------
7FF9DCB0 00000000.7FF9FEB6 Saved R2
7FF9DCB8 00000000.7FF9DE00 Saved R29

SDA> show call/next

Call Frame at 00000000.7FF9DE00
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: 00000000.7AF7C100
Handler at 00000000.7AF3D270
Return address on stack = FFFFFFFF.80170C24 AMAC$EMUL_CALL_NATIVE_C+00084

Registers saved on stack
------------------------
7FF9DE18 00000000.0000000B Saved R2
7FF9DE20 FFFFFFFF.810C6380 Saved R3 EXE$CMODEXECX
7FF9DE28 FFFFFFFF.81B15AC0 Saved R4 KTB
7FF9DE30 00000000.00000088 Saved R5
7FF9DE38 00000000.00041B04 Saved R6
7FF9DE40 00000000.7FF8BFC0 Saved R7
7FF9DE48 00000000.7FFA4F30 Saved R8
7FF9DE50 00000000.7FFABFC0 Saved R9
7FF9DE58 00000000.00000000 Saved R10
7FF9DE60 00000000.7FF1A1B2 Saved R11
7FF9DE68 00000000.7AF3D248 Saved R13
7FF9DE70 00000000.7FFD0620 Saved R15 CTL$GL_IAFEXE
7FF9DE78 00000000.7FFABFC0 Saved R29

SDA> show call/next

Call Frame at 00000000.7FFABFC0
-------------------------------
Stack Frame Procedure Descriptor
Flags: Base Register = FP, No Jacket, Native
Procedure Entry: 00000000.7AF7C060
Return address on stack = FFFFFFFF.80170C24 AMAC$EMUL_CALL_NATIVE_C+00084

Registers saved on stack
------------------------
7FFABFD0 00000000.00000000 Saved R8
7FFABFD8 FFFFFFFF.81012620 Saved R9 SYS$GB_CALLOUTS
7FFABFE0 00000000.7AF3D200 Saved R13
7FFABFE8 00000000.00000000 Saved R29

SDA> show call/next
%SDA-E-NOTINPHYS, 00000000.00000000 : virtual data not in physical memory
SDA>

By the way, this is what the main process is doing at the same time:

SDA> pthread thread

Process name: _FTA155: Extended PID: 20202EBF Thread data: "thread"
-----------------------------------------------------------------------------
Thread Name State Substate Policy Pri
------ ------------------------- --------------- ----------- ------------ ---
1 default thread blocked join 2 SCHED_OTHER 11
-3 exit-handling thread blocked SCHED_FIFO 32
2 blocked t-cv 2 SCHED_OTHER 11
3 JAVA$JAVA_VMS_SHR/DATA+0x blocked delay SCHED_OTHER 11
4 Garbage Collector Thread blocked cond 3 SCHED_OTHER 11
5 Garbage Collector Thread blocked cond 3 SCHED_OTHER 11
6 Reference Handler blocked cond 5 SCHED_OTHER 15
7 Finalizer blocked cond 6 SCHED_OTHER 14
8 blocked cond 7 SCHED_OTHER 11
9 SeedGenerator Thread blocked cond 8 SCHED_OTHER 8
32 Thread-0 blocked t-cv 9 SCHED_OTHER 11
33 Thread-1 blocked t-cv 11 SCHED_OTHER 11
34 Thread-2 blocked t-cv 12 SCHED_OTHER 11
36 Thread-3 blocked $synch 64 SCHED_OTHER 11
41 Thread-4 blocked $synch 64 SCHED_OTHER 11
42 Thread-5 blocked $synch 64 SCHED_OTHER 11
43 Thread-6 blocked $synch 64 SCHED_OTHER 11
57 Thread-7 blocked $waitfr 62 SCHED_OTHER 11
60 zombie exited SCHED_OTHER 11
SDA>

Re: Subprocess hangs if created by Java

Dominik Andelshauser — Mon, 07 Nov 2005 05:20:11 GMT

This is a bug within VMS or Java for VMS.

Because I did not get or find any solution to my problem on VMS, I now use Windows. It's by the way much faster using Java on Windows than on VMS.

Re: Subprocess hangs if created by Java

Dominik Andelshauser — Fri, 27 Mar 2009 13:43:40 GMT

For those guys who experience the same problem: Recently I found a hint in the latest Release Notes: Don't use "$ set verify" before the call to Java.
I can't verify this hint because we now use JNI instead of Runtime().exec()

Greetings
Dominik