Subprocess hangs if created by Java

[Dominik Andelshauser]

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

[Ian Miller.]

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?

[Dominik Andelshauser]

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

[Ian Miller.]

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

[Dominik Andelshauser]

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

[Ian Miller.]

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

[Dominik Andelshauser]

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?

[Ian Miller.]

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?

[Dominik Andelshauser]

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>

[Ian Miller.]

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

in SDA before those SHOW CALL commands?