Bug 5471 – GRAM Jobs Hang in Unsubmitted State

Bug 5471 - GRAM Jobs Hang in Unsubmitted State

Summary:

GRAM Jobs Hang in Unsubmitted State

Status:	RESOLVED FIXED

Product:	GRAM
Component:	general
Version:	4.0.3
Platform:	All All

Importance:	P3 normal
Target Milestone:	---
Assigned To:	Martin Feller

URL:
Keywords:

Depends on:
Blocks:
	Show dependency tree / graph

Reported:	2007-08-06 16:31 by Patrick Doran
Modified:	2009-03-19 09:38 (History)

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note

You need to log in before you can comment on or make changes to this bug.

Description From Patrick Doran 2007-08-06 16:31:04

During DDM testing we found that it is possible to get GRAM into a state where
there is a locking conflict on the fork scheduler log file, and all jobs
submitted while GRAM is in this state hang in an unsubmitted state.

During normal operation, DDM submits GRAM multijobs running across two nodes to
enact data transfers using rsync. These jobs do not use data staging, and we
explicitly destroy the jobs when we finish processing a transfer. 

Restarting the container clears this state, and some posts suggest that
deleting the fork log stamp files may clear the error as well. 

The error occurred only intermittently, and we observed the error condition on
RedHat 4 and SuSE 9. 

We managed to produce this issue with GRAM debugging on. The GRAM job
submission looks normal but we get the following message repeated in the logs:

2007-08-03 11:15:04,276 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,startSegProcess:226] Starting seg process
2007-08-03 11:15:04,276 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,startSegProcess:245] executing command: 
2007-08-03 11:15:04,276 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,startSegProcess:248]
->/usr/local/ug-2.0/libexec/globus-scheduler-event-generator
2007-08-03 11:15:04,276 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,startSegProcess:248] ->-s
2007-08-03 11:15:04,277 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,startSegProcess:248] ->multi
2007-08-03 11:15:04,277 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,startSegProcess:248] ->-t
2007-08-03 11:15:04,278 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,startSegProcess:248] ->1185995802
2007-08-03 11:15:04,386 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,run:123] getting seg input
2007-08-03 11:15:04,389 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,run:128] Seg input buffer is not ready
2007-08-03 11:15:04,408 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,throttleRestart:276] throttleRestart called
2007-08-03 11:15:04,409 DEBUG monitoring.SchedulerEventGenerator
[Thread-5,throttleRestart:283] Throttling the restart as we just restarted the
SEG

This appears to be a locking conflict with the Fork scheduler file. A similar
issue is described in the following two posts:

http://www-unix.globus.org/mail_archive/gt4-friends/2005/09/msg00008.html

http://www.globus.org/mail_archive/discuss/2005/06/msg00187.html

We've isntructed our engineers to do the following of they see this issue
again:

- Delete all globus-fork .stamp files in $GLOBUS_LOCATION/var and see if this
clears the problem.

- If not, delete these stamp files and restart the containers. 

These are fixes suggested in the post. I suspect deleting the stamp files
should resolve this issue.

Here is the container log segment from the a job that hung in the unsubmitted
state:

2007-08-03 10:19:03,743 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:83] Entering createManaagedJob()
2007-08-03 10:19:03,745 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:111] requested termination time: Sat Aug 04
10:19:03 CDT 2007
2007-08-03 10:19:03,746 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:113] current time: Fri Aug 03 10:19:03 CDT
2007
2007-08-03 10:19:03,748 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:120] setting job resource termination time
to requested time
2007-08-03 10:19:03,765 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:160] received RSL : 
<ns1:job
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job/description"><ns1:factoryEndpoint><ns2:Address
xmlns:ns2="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://localhost:8443/wsrf/services/ManagedJobFactoryService</ns2:Address><ns3:ReferenceProperties
xmlns:ns3="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns5:ResourceID
ns04:type="ns05:string" xmlns:ns04="http://www.w3.org/2001/XMLSchema-instance"
xmlns:ns05="http://www.w3.org/2001/XMLSchema"
xmlns:ns5="http://www.globus.org/namespaces/2004/10/gram/job">Fork</ns5:ResourceID></ns3:ReferenceProperties><ns4:ReferenceParameters
xmlns:ns4="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:factoryEndpoint><ns1:executable>/bin/date</ns1:executable></ns1:job>
2007-08-03 10:19:03,768 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:184] servicePath=ManagedJobFactoryService
2007-08-03 10:19:03,769 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:212] createManagedJob() called...
Caller ID:
/O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
Looked up local user ID: jini
2007-08-03 10:19:03,771 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:224] received a single-job RSL
2007-08-03 10:19:03,772 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:274] Managed Job Service Path:
ManagedExecutableJobService
2007-08-03 10:19:03,777 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:289] at create()
2007-08-03 10:19:03,780 DEBUG utils.PersistenceHelper
[ServiceThread-47,load:138] loading resource
org.globus.exec.service.exec.PersistentManagedExecutableJobResource@1718486 of
key
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:03,783 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:305] JobID Specified, but not a duplicate
job id
2007-08-03 10:19:03,786 DEBUG utils.PersistenceHelper
[ServiceThread-47,load:138] loading resource
org.globus.exec.service.exec.PersistentManagedExecutableJobResource@1b391bf of
key
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:03,788 DEBUG exec.ManagedExecutableJobHome
[ServiceThread-47,create:273] new resource being created
2007-08-03 10:19:03,802 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285
[ServiceThread-47,resolveVariables:771] Entering resolveVariables()
2007-08-03 10:19:03,804 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285
[ServiceThread-47,resolveVariables:1276] Leaving resolveVariables()
2007-08-03 10:19:03,807 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:49] processing 28 properties...
2007-08-03 10:19:03,808 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property argument...
2007-08-03 10:19:03,809 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property count...
2007-08-03 10:19:03,811 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property directory...
2007-08-03 10:19:03,812 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property environment...
2007-08-03 10:19:03,814 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property executable...
2007-08-03 10:19:03,815 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property extensions...
2007-08-03 10:19:03,816 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property factoryEndpoint...
2007-08-03 10:19:03,818 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property fileCleanUp...
2007-08-03 10:19:03,819 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property fileStageIn...
2007-08-03 10:19:03,821 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property fileStageOut...
2007-08-03 10:19:03,822 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property holdState...
2007-08-03 10:19:03,824 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property hostCount...
2007-08-03 10:19:03,826 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property jobCredentialEndpoint...
2007-08-03 10:19:03,827 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property jobType...
2007-08-03 10:19:03,829 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property libraryPath...
2007-08-03 10:19:03,830 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property localUserId...
2007-08-03 10:19:03,832 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property maxCpuTime...
2007-08-03 10:19:03,833 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property maxMemory...
2007-08-03 10:19:03,820 DEBUG impl.SubItemHandler [Logical Metadata Thread -
4,writeQueuedItems:232] Entering writeQueuedItems
2007-08-03 10:19:03,835 DEBUG impl.SubItemHandler [Logical Metadata Thread -
4,writeQueuedItems:240] Writting queued items to  itemsToWrite count : 0
2007-08-03 10:19:03,836 DEBUG impl.SubItemHandler [Logical Metadata Thread -
4,writeQueuedItems:262] Copying overflow items to itemsToWrite count : 0
2007-08-03 10:19:03,835 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property maxTime...
2007-08-03 10:19:03,838 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property maxWallTime...
2007-08-03 10:19:03,840 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property minMemory...
2007-08-03 10:19:03,842 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property project...
2007-08-03 10:19:03,843 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property queue...
2007-08-03 10:19:03,845 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property stagingCredentialEndpoint...
2007-08-03 10:19:03,846 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property stderr...
2007-08-03 10:19:03,847 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property stdin...
2007-08-03 10:19:03,848 DEBUG utils.JobDescriptionMap
[ServiceThread-47,<init>:60] processing property stdout...
2007-08-03 10:19:03,850 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
directory/directory
2007-08-03 10:19:03,851 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute directory is of type
java.lang.String
2007-08-03 10:19:03,853 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
maxCpuTime/maxcputime
2007-08-03 10:19:03,854 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name condorOs/condoros
2007-08-03 10:19:03,855 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute condoros is of type
java.lang.String
2007-08-03 10:19:03,856 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
fileStageIn/filestagein
2007-08-03 10:19:03,857 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
maxMemory/maxmemory
2007-08-03 10:19:03,858 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
minMemory/minmemory
2007-08-03 10:19:03,859 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
condorArch/condorarch
2007-08-03 10:19:03,861 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute condorarch is of type
java.lang.String
2007-08-03 10:19:03,862 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name stderr/stderr
2007-08-03 10:19:03,863 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute stderr is of type
java.lang.String
2007-08-03 10:19:03,864 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
environment/environment
2007-08-03 10:19:03,865 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute environment is of type
[Lorg.globus.exec.generated.NameValuePairType;
2007-08-03 10:19:03,866 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:180] Attribute environment has component type
org.globus.exec.generated.NameValuePairType
2007-08-03 10:19:03,867 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:186] Attribute environment being processed as
NameValuePairType[]
2007-08-03 10:19:03,869 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
extensions/extensions
2007-08-03 10:19:03,870 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
jobCredentialEndpoint/jobcredentialendpoint
2007-08-03 10:19:03,871 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
hostCount/hostcount
2007-08-03 10:19:03,872 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
xmlextensions/xmlextensions
2007-08-03 10:19:03,873 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute xmlextensions is of type
java.lang.String
2007-08-03 10:19:03,874 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name queue/queue
2007-08-03 10:19:03,876 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
localUserId/localuserid
2007-08-03 10:19:03,877 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
arguments/arguments
2007-08-03 10:19:03,878 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
fileStageOut/filestageout
2007-08-03 10:19:03,880 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
executable/executable
2007-08-03 10:19:03,881 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute executable is of type
java.lang.String
2007-08-03 10:19:03,882 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
stagingCredentialEndpoint/stagingcredentialendpoint
2007-08-03 10:19:03,883 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
factoryEndpoint/factoryendpoint
2007-08-03 10:19:03,884 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute factoryendpoint is of type
org.apache.axis.message.addressing.EndpointReferenceType
2007-08-03 10:19:03,888 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
holdState/holdstate
2007-08-03 10:19:03,889 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name stdin/stdin
2007-08-03 10:19:03,890 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:151] appending stdin = /dev/null
2007-08-03 10:19:03,891 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
fileCleanUp/filecleanup
2007-08-03 10:19:03,892 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name jobdir/jobdir
2007-08-03 10:19:03,893 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute jobdir is of type
java.lang.String
2007-08-03 10:19:03,895 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name jobType/jobtype
2007-08-03 10:19:03,896 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name stdout/stdout
2007-08-03 10:19:03,898 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute stdout is of type
java.lang.String
2007-08-03 10:19:03,899 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
maxWallTime/maxwalltime
2007-08-03 10:19:03,900 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name project/project
2007-08-03 10:19:03,901 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name count/count
2007-08-03 10:19:03,902 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute count is of type
org.apache.axis.types.PositiveInteger
2007-08-03 10:19:03,903 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
libraryPath/librarypath
2007-08-03 10:19:03,905 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name
useForkStarter/useforkstarter
2007-08-03 10:19:03,906 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:172] Attribute useforkstarter is of type
java.lang.String
2007-08-03 10:19:03,907 DEBUG exec.PerlJobDescription
[ServiceThread-47,toPerlString:130] processing attribute name maxTime/maxtime
2007-08-03 10:19:03,909 DEBUG exec.ManagedExecutableJobHome
[ServiceThread-47,create:311] Created ManagedExecutableJobResource with key
value de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:03,911 DEBUG utils.PersistenceHelper
[ServiceThread-47,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
with state Unsubmitted
2007-08-03 10:19:03,913 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285
[ServiceThread-47,setResourceDatum:146] Setting resource datum topicListener to
value [Lorg.globus.exec.generated.TopicListenerDescriptionType;@25b659
2007-08-03 10:19:03,924 DEBUG exec.PersistentManagedExecutableJobResource
[ServiceThread-47,setDirty:308] setting dirty flag to false
2007-08-03 10:19:03,925 DEBUG utils.PersistenceHelper
[ServiceThread-47,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:03,927 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:329] at find()
2007-08-03 10:19:03,928 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:345] at subscribe()
2007-08-03 10:19:03,953 DEBUG utils.PersistenceHelper
[ServiceThread-47,store:77] Dirty flag not set: resource will not be stored
2007-08-03 10:19:03,955 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:356] at start()
2007-08-03 10:19:03,956 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285
[ServiceThread-47,getInternalState:1661] getting resource datum internalState
2007-08-03 10:19:03,957 DEBUG exec.RunQueue [ServiceThread-47,getInstance:102]
Getting RunQueue instance #5
2007-08-03 10:19:03,958 DEBUG exec.RunQueue [ServiceThread-47,getInstance:106]
Returning RunQueue instance: org.globus.exec.service.exec.RunQueue@1c2e5bb
2007-08-03 10:19:03,959 DEBUG exec.RunQueue [ServiceThread-47,add:62] adding
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
to queue.
2007-08-03 10:19:03,960 DEBUG exec.RunQueue [ServiceThread-47,add:69] 
RunQueue Other Graph: *
2007-08-03 10:19:03,961 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:373] createManagedJob() exit
2007-08-03 10:19:03,962 DEBUG ManagedJobFactoryService.performance
[ServiceThread-47,stop:71] [createManagedJob][ServiceThread-47][218]
2007-08-03 10:19:03,963 DEBUG factory.ManagedJobFactoryService
[ServiceThread-47,createManagedJob:383] Entering createManaagedJob()
2007-08-03 10:19:03,967 DEBUG exec.RunQueue [RunQueue Other-1,remove:84]
removing
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
from queue.
2007-08-03 10:19:03,967 DEBUG exec.RunQueue [RunQueue Other-1,remove:91] 
RunQueue Other Graph: 
2007-08-03 10:19:03,968 DEBUG exec.RunThread [RunQueue Other-1,run:88]
Processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:03,968 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,getInternalState:1661] getting resource datum internalState
2007-08-03 10:19:03,969 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,getResourceDatum:217] getting resource datum canceled
2007-08-03 10:19:03,970 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,getResourceDatum:217] getting resource datum userCancelRequested
2007-08-03 10:19:03,976 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,getResourceDatum:217] getting resource datum systemCancelRequested
2007-08-03 10:19:03,976 DEBUG exec.StateMachine [RunQueue
Other-1,processState:305] [resourceKey:de7fef40-41d4-11dc-8681-000c29c39285]
processing internal state None
2007-08-03 10:19:03,977 DEBUG exec.StateMachine [RunQueue
Other-1,processState:313] [resourceKey:de7fef40-41d4-11dc-8681-000c29c39285] 
------------------------------------------------------
PROCESSING INTERNAL STATE:  -- None --
------------------------------------------------------
2007-08-03 10:19:03,977 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,getResourceDatum:217] getting resource datum notifiedJobData
2007-08-03 10:19:03,979 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,setResourceDatum:146] Setting resource datum started to value true
2007-08-03 10:19:03,979 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to true
2007-08-03 10:19:03,980 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
with state Unsubmitted
2007-08-03 10:19:03,981 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@1b0e313
2007-08-03 10:19:03,995 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to false
2007-08-03 10:19:03,996 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:03,996 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,getResourceDatum:217] getting resource datum holdState
2007-08-03 10:19:04,000 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,setInternalState:1690] Setting resource datum internalState to value
Start
2007-08-03 10:19:04,001 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to true
2007-08-03 10:19:04,002 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
with state Unsubmitted
2007-08-03 10:19:04,003 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@c2ca7
2007-08-03 10:19:04,014 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to false
2007-08-03 10:19:04,015 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,016 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-1,getInternalState:1661] getting resource datum internalState
2007-08-03 10:19:04,017 DEBUG exec.RunQueue [RunQueue Other-1,getInstance:102]
Getting RunQueue instance #5
2007-08-03 10:19:04,018 DEBUG exec.RunQueue [RunQueue Other-1,getInstance:106]
Returning RunQueue instance: org.globus.exec.service.exec.RunQueue@1c2e5bb
2007-08-03 10:19:04,019 DEBUG exec.RunQueue [RunQueue Other-1,add:62] adding
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
to queue.
2007-08-03 10:19:04,020 DEBUG exec.RunQueue [RunQueue Other-1,add:69] 
RunQueue Other Graph: *
2007-08-03 10:19:04,021 DEBUG exec.RunQueue [RunQueue Other-0,remove:84]
removing
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
from queue.
2007-08-03 10:19:04,021 DEBUG exec.RunQueue [RunQueue Other-0,remove:91] 
RunQueue Other Graph: 
2007-08-03 10:19:04,022 DEBUG exec.RunThread [RunQueue Other-0,run:88]
Processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,023 DEBUG StateMachine.performance [RunQueue
Other-1,stop:71] [processNoneState][RunQueue Other-1][44]
2007-08-03 10:19:04,023 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-0,getInternalState:1661] getting resource datum internalState
2007-08-03 10:19:04,024 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-0,getResourceDatum:217] getting resource datum canceled
2007-08-03 10:19:04,025 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-0,getResourceDatum:217] getting resource datum userCancelRequested
2007-08-03 10:19:04,026 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-0,getResourceDatum:217] getting resource datum systemCancelRequested
2007-08-03 10:19:04,026 DEBUG exec.StateMachine [RunQueue
Other-0,processState:305] [resourceKey:de7fef40-41d4-11dc-8681-000c29c39285]
processing internal state Start
2007-08-03 10:19:04,027 DEBUG exec.StateMachine [RunQueue
Other-0,processState:313] [resourceKey:de7fef40-41d4-11dc-8681-000c29c39285] 
------------------------------------------------------
PROCESSING INTERNAL STATE:  -- Start --
------------------------------------------------------
2007-08-03 10:19:04,027 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-0,getResourceDatum:217] getting resource datum notifiedJobData
2007-08-03 10:19:04,028 INFO  exec.StateMachine [RunQueue
Other-0,logJobAccepted:3240] Job de7fef40-41d4-11dc-8681-000c29c39285 accepted
for local user 'jini'
2007-08-03 10:19:04,029 DEBUG exec.StateMachine [RunQueue
Other-0,processStartState:629]
[resourceKey:de7fef40-41d4-11dc-8681-000c29c39285] Skipping StageIn and going
straight to Submit
2007-08-03 10:19:04,030 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-0,setInternalState:1690] Setting resource datum internalState to value
Submit
2007-08-03 10:19:04,031 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-0,setDirty:308] setting dirty flag to true
2007-08-03 10:19:04,031 DEBUG utils.PersistenceHelper [RunQueue
Other-0,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
with state Unsubmitted
2007-08-03 10:19:04,033 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-0,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@147c583
2007-08-03 10:19:04,031 DEBUG exec.RunThread [RunQueue Other-1,run:104]
processState returned
2007-08-03 10:19:04,042 DEBUG exec.RunThread [RunQueue Other-1,run:109] Done
processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,044 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-0,setDirty:308] setting dirty flag to false
2007-08-03 10:19:04,045 DEBUG utils.PersistenceHelper [RunQueue
Other-0,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,046 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Other-0,getInternalState:1661] getting resource datum internalState
2007-08-03 10:19:04,047 DEBUG exec.RunQueue [RunQueue Other-0,getInstance:102]
Getting RunQueue instance #1
2007-08-03 10:19:04,048 DEBUG exec.RunQueue [RunQueue Other-0,getInstance:106]
Returning RunQueue instance: org.globus.exec.service.exec.RunQueue@1799345
2007-08-03 10:19:04,049 DEBUG exec.RunQueue [RunQueue Other-0,add:62] adding
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
to queue.
2007-08-03 10:19:04,050 DEBUG exec.RunQueue [RunQueue Other-0,add:69] 
RunQueue Submit Graph: *
2007-08-03 10:19:04,050 DEBUG StateMachine.performance [RunQueue
Other-0,stop:71] [processStartState][RunQueue Other-0][22]
2007-08-03 10:19:04,051 DEBUG exec.RunThread [RunQueue Other-0,run:104]
processState returned
2007-08-03 10:19:04,051 DEBUG exec.RunThread [RunQueue Other-0,run:109] Done
processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,052 DEBUG exec.RunQueue [RunQueue Submit-2,remove:84]
removing
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
from queue.
2007-08-03 10:19:04,053 DEBUG exec.RunQueue [RunQueue Submit-2,remove:91] 
RunQueue Submit Graph: 
2007-08-03 10:19:04,054 DEBUG exec.RunThread [RunQueue Submit-2,run:88]
Processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,054 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getInternalState:1661] getting resource datum internalState
2007-08-03 10:19:04,055 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum canceled
2007-08-03 10:19:04,055 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum userCancelRequested
2007-08-03 10:19:04,056 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum systemCancelRequested
2007-08-03 10:19:04,057 DEBUG exec.StateMachine [RunQueue
Submit-2,processState:305] [resourceKey:de7fef40-41d4-11dc-8681-000c29c39285]
processing internal state Submit
2007-08-03 10:19:04,057 DEBUG exec.StateMachine [RunQueue
Submit-2,processState:313] [resourceKey:de7fef40-41d4-11dc-8681-000c29c39285] 
------------------------------------------------------
PROCESSING INTERNAL STATE:  -- Submit --
------------------------------------------------------
2007-08-03 10:19:04,058 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum notifiedJobData
2007-08-03 10:19:04,058 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum holdState
2007-08-03 10:19:04,059 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum localResourceManager
2007-08-03 10:19:04,060 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name directory/directory
2007-08-03 10:19:04,061 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute directory is of type java.lang.String
2007-08-03 10:19:04,061 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name maxCpuTime/maxcputime
2007-08-03 10:19:04,062 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name condorOs/condoros
2007-08-03 10:19:04,063 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute condoros is of type java.lang.String
2007-08-03 10:19:04,064 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name fileStageIn/filestagein
2007-08-03 10:19:04,064 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name maxMemory/maxmemory
2007-08-03 10:19:04,065 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name minMemory/minmemory
2007-08-03 10:19:04,066 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name
useforkstarter/useforkstarter
2007-08-03 10:19:04,067 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute useforkstarter is of type java.lang.String
2007-08-03 10:19:04,068 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name condorArch/condorarch
2007-08-03 10:19:04,068 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute condorarch is of type java.lang.String
2007-08-03 10:19:04,069 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name stderr/stderr
2007-08-03 10:19:04,070 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute stderr is of type java.lang.String
2007-08-03 10:19:04,071 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name environment/environment
2007-08-03 10:19:04,072 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute environment is of type
[Lorg.globus.exec.generated.NameValuePairType;
2007-08-03 10:19:04,072 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:180] Attribute environment has component type
org.globus.exec.generated.NameValuePairType
2007-08-03 10:19:04,073 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:186] Attribute environment being processed as
NameValuePairType[]
2007-08-03 10:19:04,083 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name extensions/extensions
2007-08-03 10:19:04,085 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name
jobCredentialEndpoint/jobcredentialendpoint
2007-08-03 10:19:04,085 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name hostCount/hostcount
2007-08-03 10:19:04,086 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name
xmlextensions/xmlextensions
2007-08-03 10:19:04,087 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute xmlextensions is of type java.lang.String
2007-08-03 10:19:04,088 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name queue/queue
2007-08-03 10:19:04,088 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name localUserId/localuserid
2007-08-03 10:19:04,089 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name arguments/arguments
2007-08-03 10:19:04,100 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name fileStageOut/filestageout
2007-08-03 10:19:04,101 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name executable/executable
2007-08-03 10:19:04,102 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute executable is of type java.lang.String
2007-08-03 10:19:04,103 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name
stagingCredentialEndpoint/stagingcredentialendpoint
2007-08-03 10:19:04,103 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name
factoryEndpoint/factoryendpoint
2007-08-03 10:19:04,104 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute factoryendpoint is of type
org.apache.axis.message.addressing.EndpointReferenceType
2007-08-03 10:19:04,124 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name holdState/holdstate
2007-08-03 10:19:04,125 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name stdin/stdin
2007-08-03 10:19:04,127 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:151] appending stdin = /dev/null
2007-08-03 10:19:04,127 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name fileCleanUp/filecleanup
2007-08-03 10:19:04,129 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name
expand_globus_home/expandglobushome
2007-08-03 10:19:04,129 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute expandglobushome is of type
java.lang.String
2007-08-03 10:19:04,140 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name jobdir/jobdir
2007-08-03 10:19:04,141 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute jobdir is of type java.lang.String
2007-08-03 10:19:04,142 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name jobType/jobtype
2007-08-03 10:19:04,143 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name stdout/stdout
2007-08-03 10:19:04,143 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute stdout is of type java.lang.String
2007-08-03 10:19:04,144 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name maxWallTime/maxwalltime
2007-08-03 10:19:04,145 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name project/project
2007-08-03 10:19:04,145 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name
expand_globus_location/expandglobuslocation
2007-08-03 10:19:04,146 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute expandglobuslocation is of type
java.lang.String
2007-08-03 10:19:04,147 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name count/count
2007-08-03 10:19:04,148 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute count is of type
org.apache.axis.types.PositiveInteger
2007-08-03 10:19:04,148 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name libraryPath/librarypath
2007-08-03 10:19:04,149 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name
useForkStarter/useforkstarter
2007-08-03 10:19:04,158 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:172] Attribute useforkstarter is of type java.lang.String
2007-08-03 10:19:04,159 DEBUG exec.PerlJobDescription [RunQueue
Submit-2,toPerlString:130] processing attribute name maxTime/maxtime
2007-08-03 10:19:04,160 DEBUG exec.StateMachine [RunQueue
Submit-2,runScript:2915] Perl Job Description: $description = {
    directory => [ '/home/jini' ],
    condoros => [ 'LINUX' ],
    useforkstarter => [ '1' ],
    condorarch => [ 'INTEL' ],
    stderr => [ '/dev/null' ],
    environment => [ [ 'GLOBUS_LOCATION', '/usr/local/ug-2.0' ], [
'X509_CERT_DIR', '/etc/grid-security/certificates' ], [ 'X509_USER_PROXY', ''
], [ 'X509_USER_CERT', '' ], [ 'X509_USER_KEY', '' ], [ 'HOME', '/home/jini' ],
[ 'LOGNAME', 'jini' ], [ 'SCRATCH_DIRECTORY', '/home/jini/.globus/scratch' ], [
'JAVA_HOME', '/usr/local/bin/java/jre' ], [ 'GLOBUS_GRAM_JOB_HANDLE',
'https://192.168.31.98:8443/wsrf/services/ManagedExecutableJobService?de7fef40-41d4-11dc-8681-000c29c39285'
],  ],
    xmlextensions => [ '1' ],
    executable => [ '/bin/date' ],
    factoryendpoint => [ 'Address:
https://localhost:8443/wsrf/services/ManagedJobFactoryService
Reference property[0]:
<ns5:ResourceID ns04:type="ns05:string"
xmlns:ns04="http://www.w3.org/2001/XMLSchema-instance"
xmlns:ns05="http://www.w3.org/2001/XMLSchema"
xmlns:ns5="http://www.globus.org/namespaces/2004/10/gram/job">Fork</ns5:ResourceID>
' ],
    stdin => [ '/dev/null' ],
    expandglobushome => [ '1' ],
    jobdir => [ '/home/jini/.globus/de7fef40-41d4-11dc-8681-000c29c39285' ],
    jobtype => [ 'multiple' ],
    stdout => [ '/dev/null' ],
    expandglobuslocation => [ '1' ],
    count => [ '1' ],
    useforkstarter => [ '1' ],
};

2007-08-03 10:19:04,161 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum localResourceManager
2007-08-03 10:19:04,286 DEBUG utils.GlobusShToolsProperties [RunQueue
Submit-2,getInstance:43] entering getInstance()
2007-08-03 10:19:04,287 DEBUG utils.GlobusShToolsProperties [RunQueue
Submit-2,getInstance:75] leaving getInstance()
2007-08-03 10:19:04,288 DEBUG utils.AuthorizationHelper [RunQueue
Submit-2,isAuthorizationGridmap:70] Entering/Exiting isAuthorizationGridmap()
2007-08-03 10:19:04,291 DEBUG exec.JobManagerScript [Thread-1126,run:208]
Executing command:
/usr/bin/sudo -H -u jini -S
/usr/local/ug-2.0/libexec/globus-gridmap-and-execute -g
/etc/grid-security/grid-mapfile
/usr/local/ug-2.0/libexec/globus-job-manager-script.pl -m fork -f
/usr/local/ug-2.0/tmp/gram_job_mgr3257.tmp -c submit
2007-08-03 10:19:04,497 DEBUG exec.JobManagerScript [Thread-1126,run:225] first
line: GRAM_SCRIPT_JOB_ID:df0617f0-41d4-11dc-9174-000c29c39285:27652
2007-08-03 10:19:04,498 DEBUG exec.JobManagerScript [Thread-1126,run:240]
Received local job ID df0617f0-41d4-11dc-9174-000c29c39285:27652
2007-08-03 10:19:04,510 DEBUG exec.JobManagerScript [Thread-1126,run:335]
failure message: null
2007-08-03 10:19:04,512 DEBUG exec.JobManagerScript [Thread-1126,setDone:345]
script is done, setting done flag
2007-08-03 10:19:04,513 DEBUG exec.StateMachine [RunQueue
Submit-2,processSubmitState:1188] script return code: 0
2007-08-03 10:19:04,514 DEBUG exec.StateMachine [RunQueue
Submit-2,processSubmitState:1220] script returned job state: Active
2007-08-03 10:19:04,515 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum localJobId
2007-08-03 10:19:04,516 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,getResourceDatum:217] getting resource datum localJobState
2007-08-03 10:19:04,517 DEBUG exec.StateMachine [RunQueue
Submit-2,setLocalJobId:2973] Saving local job ID
df0617f0-41d4-11dc-9174-000c29c39285:27652
2007-08-03 10:19:04,518 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,setResourceDatum:146] Setting resource datum localJobId to value
[Ljava.lang.String;@f8506e
2007-08-03 10:19:04,519 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-2,setDirty:308] setting dirty flag to true
2007-08-03 10:19:04,520 DEBUG utils.PersistenceHelper [RunQueue
Submit-2,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
with state Unsubmitted
2007-08-03 10:19:04,522 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@687290
2007-08-03 10:19:04,539 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-2,setDirty:308] setting dirty flag to false
2007-08-03 10:19:04,540 DEBUG utils.PersistenceHelper [RunQueue
Submit-2,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,541 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,setResourceDatum:146] Setting resource datum localJobState to value
[Lorg.globus.exec.generated.StateEnumeration;@1397841
2007-08-03 10:19:04,542 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-2,setDirty:308] setting dirty flag to true
2007-08-03 10:19:04,543 DEBUG utils.PersistenceHelper [RunQueue
Submit-2,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
with state Unsubmitted
2007-08-03 10:19:04,544 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@6264b
2007-08-03 10:19:04,554 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-2,setDirty:308] setting dirty flag to false
2007-08-03 10:19:04,555 DEBUG utils.PersistenceHelper [RunQueue
Submit-2,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,556 DEBUG exec.StateMachine [RunQueue
Submit-2,processSubmitState:1240] Subscribing job
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
to SEG events for local job ID df0617f0-41d4-11dc-9174-000c29c39285:27652
2007-08-03 10:19:04,557 DEBUG utils.JobStateMonitorSubscriptionManager
[RunQueue Submit-2,add:103] adding
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
to queue.
2007-08-03 10:19:04,558 DEBUG
ManagedExecutableJobResource.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,setInternalState:1690] Setting resource datum internalState to value
WaitingForStateChanges
2007-08-03 10:19:04,559 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-2,setDirty:308] setting dirty flag to true
2007-08-03 10:19:04,560 DEBUG utils.PersistenceHelper [RunQueue
Submit-2,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
with state Unsubmitted
2007-08-03 10:19:04,561 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285 [RunQueue
Submit-2,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@1bc2fff
2007-08-03 10:19:04,562 DEBUG
ManagedJobResourceImpl.de7fef40-41d4-11dc-8681-000c29c39285
[Thread-144,getResourceDatum:217] getting resource datum localJobId
2007-08-03 10:19:04,576 DEBUG monitoring.JobStateMonitor
[Thread-144,registerJobID:223] Entering registerJobID:
df0617f0-41d4-11dc-9174-000c29c39285:27652
2007-08-03 10:19:04,577 DEBUG monitoring.JobStateMonitor
[Thread-144,getCachedEvents:396] Entering getCachedEvents()
2007-08-03 10:19:04,578 DEBUG monitoring.JobStateMonitor
[Thread-144,getCachedEvents:412] Exiting getCachedEvents()
2007-08-03 10:19:04,584 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-2,setDirty:308] setting dirty flag to false
2007-08-03 10:19:04,585 DEBUG utils.PersistenceHelper [RunQueue
Submit-2,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,633 DEBUG StateMachine.performance [RunQueue
Submit-2,stop:71] [processSubmitState][RunQueue Submit-2][575]
2007-08-03 10:19:04,634 DEBUG exec.RunThread [RunQueue Submit-2,run:104]
processState returned
2007-08-03 10:19:04,634 DEBUG exec.RunThread [RunQueue Submit-2,run:109] Done
processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,635 DEBUG monitoring.JobStateMonitor
[Thread-144,registerJobID:239] Exiting registerJobID
2007-08-03 10:19:04,638 DEBUG utils.JobStateMonitorSubscriptionManager
[Thread-144,run:188] Done processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=de7fef40-41d4-11dc-8681-000c29c39285
2007-08-03 10:19:04,736 DEBUG transfer.TransferResource
[ServiceThread-23,getSecurityDescriptor:613] Granting Access to subject with
DN: /O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,739 DEBUG transfer.TransferResource
[ServiceThread-23,getSecurityDescriptor:613] Granting Access to subject with
DN: /O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,742 DEBUG transfer.TransferResource
[ServiceThread-23,getSecurityDescriptor:613] Granting Access to subject with
DN: /O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,744 DEBUG transfer.TransferResource
[ServiceThread-23,getSecurityDescriptor:613] Granting Access to subject with
DN: /O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,747 DEBUG impl.SecurityServiceImpl
[ServiceThread-23,hasAdminPermission:136] hasAdminPermission: hit on
permit=admin for
subject=/O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,865 DEBUG transfer.TransferResource
[ServiceThread-22,getSecurityDescriptor:613] Granting Access to subject with
DN: /O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,867 DEBUG transfer.TransferResource
[ServiceThread-22,getSecurityDescriptor:613] Granting Access to subject with
DN: /O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,869 DEBUG transfer.TransferResource
[ServiceThread-22,getSecurityDescriptor:613] Granting Access to subject with
DN: /O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,870 DEBUG transfer.TransferResource
[ServiceThread-22,getSecurityDescriptor:613] Granting Access to subject with
DN: /O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:04,872 DEBUG impl.SecurityServiceImpl
[ServiceThread-22,hasAdminPermission:136] hasAdminPermission: hit on
permit=admin for
subject=/O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=jini
2007-08-03 10:19:05,009 DEBUG monitoring.JobStateMonitor
[Thread-2,flushCache:329] Entering flushCache()
2007-08-03 10:19:05,010 DEBUG monitoring.JobStateMonitor
[Thread-2,flushCache:369] Exiting flushCache()
2007-08-03 10:19:05,011 DEBUG monitoring.JobStateMonitor
[Thread-2,flushCache:329] Entering flushCache()
2007-08-03 10:19:05,012 DEBUG monitoring.JobStateMonitor
[Thread-2,flushCache:369] Exiting flushCache()

------- Comment #1 From Stuart Martin 2007-08-09 11:45:23 -------

Starting a seg for multi service is not the problem.  multi-jobs don't use a
seg for monitoring the individual gram jobs.  I think this has been fixed in
4.0.5.  When a job hangs, you should try and see if there is a an entry for the
fork job in the fork seg file.  If so, then with debugging turned on, the job
state monitor should get information of the new job state, which would then
cause the job state resource property to be updated and clients (multijob
service in this case) to be notified.  So the thing to debug will be where in
the chain is the update/notification being dropped/missed.

-Stu

------- Comment #2 From Patrick Doran 2007-08-10 10:28:23 -------

Is there a CR addressed in 4.0.5 that we think would fix this issue?

So, the SEG input buffer message is OK. What should I be looking for to
determine where notificatons are being lost? The job submission entries for the
job that hung look innocuous.

------- Comment #3 From Patrick Doran 2007-08-10 10:31:25 -------

Also, one the container gets into this bad state, even simple /bin/date jobs
hang, and from my monitoring code it does not look like the root DDM multijob
is moving to a submitted state. So, I'm not sure that this issue is specific to
the subjobs.

------- Comment #4 From Patrick Doran 2007-08-10 13:30:22 -------

We were able to reproduce this issue again, and it looks like the two subjobs
from the multijob completed and transferred our file but the multijob never
leaves the unsubmitted state. Does this fit the symptoms for the issue we think
is fixed in 4.0.5?

I'll attach logs of the multijob submission in a separate comment.

------- Comment #5 From Patrick Doran 2007-08-10 13:32:16 -------

2007-08-10 10:32:52,823 INFO  client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,submit:428] <startTime
name="submission">1186759972823</startTime>
2007-08-10 10:32:52,828 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,submit:445] Factory EPR Override:
<ns1:factoryEndpoint
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job/description"
xmlns:ns2="http://schemas.xmlsoap.org/ws/2004/03/addressing"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns2:EndpointReferenceType">
 <ns2:Address
xsi:type="ns2:AttributedURI">https://jini-suse-ddm.univa.com:8443/wsrf/services/ManagedJobFactoryService</ns2:Address>
 <ns2:ReferenceProperties xsi:type="ns2:ReferencePropertiesType">
  <ns4:ResourceID xmlns:ns4="http://www.globus.org/namespaces/2004/10/gram/job"
xmlns:ns5="http://www.globus.org/foobar"
xsi:type="ns5:QueryExpressionDialect">Multi</ns4:ResourceID>
 </ns2:ReferenceProperties>
 <ns2:ReferenceParameters xsi:type="ns2:ReferenceParametersType"/>
</ns1:factoryEndpoint>
2007-08-10 10:32:52,831 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,submit:461] Factory EPR:
<ns1:factoryEndpoint
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job/description"
xmlns:ns2="http://schemas.xmlsoap.org/ws/2004/03/addressing"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns2:EndpointReferenceType">
 <ns2:Address
xsi:type="ns2:AttributedURI">https://jini-suse-ddm.univa.com:8443/wsrf/services/ManagedJobFactoryService</ns2:Address>
 <ns2:ReferenceProperties xsi:type="ns2:ReferencePropertiesType">
  <ns4:ResourceID xmlns:ns4="http://www.globus.org/namespaces/2004/10/gram/job"
xmlns:ns5="http://www.globus.org/foobar"
xsi:type="ns5:QueryExpressionDialect">Multi</ns4:ResourceID>
 </ns2:ReferenceProperties>
 <ns2:ReferenceParameters xsi:type="ns2:ReferenceParametersType"/>
</ns1:factoryEndpoint>
2007-08-10 10:32:52,831 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,setSecurityTypeFromEndpoint:491] Factory
Endpoint Address URL Scheme:
https
2007-08-10 10:32:52,832 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,setSecurityTypeFromEndpoint:504] using
transport-level security
2007-08-10 10:32:52,832 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,submit:474] Job Submission ID:
uuid:f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:52,841 DEBUG impl.SubItemHandler [Logical Metadata Thread -
1,writeQueuedItems:232] Entering writeQueuedItems
2007-08-10 10:32:52,843 DEBUG impl.SubItemHandler [Logical Metadata Thread -
1,writeQueuedItems:240] Writting queued items to  itemsToWrite count : 0
2007-08-10 10:32:52,843 DEBUG impl.SubItemHandler [Logical Metadata Thread -
1,writeQueuedItems:262] Copying overflow items to itemsToWrite count : 0
2007-08-10 10:32:52,844 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,setStubSecurityProperties:1818] setting
factory stub security...using authz method
org.globus.wsrf.impl.security.authorization.HostAuthorization@2c4f5c
2007-08-10 10:32:52,845 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,createJobEndpoint:887] creating ManagedJob
instance
2007-08-10 10:32:52,845 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,createJobEndpoint:894] submission time, in
seconds from the Epoch:
before: 1186759972.845
2007-08-10 10:32:52,845 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,createJobEndpoint:896]
before, in milliseconds: 1186759972845
2007-08-10 10:32:52,846 INFO  client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,createJobEndpoint:951] <startTime
name="createManagedJob">1186759972846</startTime>
2007-08-10 10:32:52,982 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:83] Entering createManaagedJob()
2007-08-10 10:32:52,983 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:111] requested termination time: Sat Aug 11
10:32:52 CDT 2007
2007-08-10 10:32:52,985 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:113] current time: Fri Aug 10 10:32:52 CDT
2007
2007-08-10 10:32:52,985 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:120] setting job resource termination time
to requested time
2007-08-10 10:32:53,031 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:160] received RSL :
<ns1:job
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job/description"><ns1:factoryEndpoint><ns2:Address
xmlns:ns2="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://jini-suse-ddm.univa.com:8443/wsrf/services/ManagedJobFactoryService</ns2:Address><ns3:ReferenceProperties
xmlns:ns3="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns4:ResourceID
xmlns:ns4="http://www.globus.org/namespaces/2004/10/gram/job"
xmlns:ns5="http://www.globus.org/foobar"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns5:QueryExpressionDialect">Multi</ns4:ResourceID></ns3:ReferenceProperties><ns4:ReferenceParameters
xmlns:ns4="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:factoryEndpoint><ns1:jobCredentialEndpoint><ns5:Address
xmlns:ns5="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://192.168.31.172:8443/wsrf/services/DelegationService</ns5:Address><ns6:ReferenceProperties
xmlns:ns6="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey></ns6:ReferenceProperties><ns7:ReferenceParameters
xmlns:ns7="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:jobCredentialEndpoint><ns1:stagingCredentialEndpoint><ns8:Address
xmlns:ns8="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://192.168.31.172:8443/wsrf/services/DelegationService</ns8:Address><ns9:ReferenceProperties
xmlns:ns9="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey></ns9:ReferenceProperties><ns10:ReferenceParameters
xmlns:ns10="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:stagingCredentialEndpoint><ns1:job><ns1:factoryEndpoint><ns11:Address
xmlns:ns11="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://jini-suse-ddm.univa.com:8443/wsrf/services/ManagedJobFactoryService</ns11:Address><ns12:ReferenceProperties
xmlns:ns12="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns9:ResourceID
xmlns:ns10="http://www.globus.org/foobar"
xmlns:ns9="http://www.globus.org/namespaces/2004/10/gram/job"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns10:QueryExpressionDialect">Fork</ns9:ResourceID></ns12:ReferenceProperties><ns13:ReferenceParameters
xmlns:ns13="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:factoryEndpoint><ns1:jobCredentialEndpoint><ns14:Address
xmlns:ns14="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://192.168.31.172:8443/wsrf/services/DelegationService</ns14:Address><ns15:ReferenceProperties
xmlns:ns15="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey></ns15:ReferenceProperties><ns16:ReferenceParameters
xmlns:ns16="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:jobCredentialEndpoint><ns1:stagingCredentialEndpoint><ns17:Address
xmlns:ns17="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://192.168.31.172:8443/wsrf/services/DelegationService</ns17:Address><ns18:ReferenceProperties
xmlns:ns18="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey></ns18:ReferenceProperties><ns19:ReferenceParameters
xmlns:ns19="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:stagingCredentialEndpoint><ns1:executable>/bin/sh</ns1:executable><ns1:argument>-c</ns1:argument><ns1:argument>.
${GLOBUS_LOCATION}/etc/globus-user-env.sh &amp;
${GLOBUS_LOCATION}/opt/ddm_rsync/rsync --recursive --force --verbose --verbose
--log-format=__item:%i:%l:%n --times --partial-dir=.rsync-partial
--delay-updates --rsh='${GLOBUS_LOCATION}/bin/gsi-tunnel -debug -protection
integrity -rendezvous-cmd ${GLOBUS_LOCATION}/bin/wsrf-rendezvous-client
-rendezvous-epr $GLOBUS_GRAM_MULTIJOB_HANDLE'
vanadium.univa.com:/tmp/test-dir/TC-Trans-056/file03
/tmp/test-dir/TC-Fault-045</ns1:argument><ns1:environment><ns1:name>PATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/bin:${GLOBUS_LOCATION}/sbin:/usr/local/bin:/bin:/usr/bin</ns1:value></ns1:environment><ns1:environment><ns1:name>LD_LIBRARY_PATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value></ns1:environment><ns1:environment><ns1:name>LIBPATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value></ns1:environment><ns1:stdout>${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-rsync.out</ns1:stdout><ns1:stderr>${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-rsync.err</ns1:stderr></ns1:job><ns1:job><ns1:factoryEndpoint><ns20:Address
xmlns:ns20="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://vanadium.univa.com:8443/wsrf/services/ManagedJobFactoryService</ns20:Address><ns21:ReferenceProperties
xmlns:ns21="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns14:ResourceID
xmlns:ns14="http://www.globus.org/namespaces/2004/10/gram/job"
xmlns:ns15="http://www.globus.org/foobar"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns15:QueryExpressionDialect">Fork</ns14:ResourceID></ns21:ReferenceProperties><ns22:ReferenceParameters
xmlns:ns22="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:factoryEndpoint><ns1:jobCredentialEndpoint><ns23:Address
xmlns:ns23="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://192.168.31.54:8443/wsrf/services/DelegationService</ns23:Address><ns24:ReferenceProperties
xmlns:ns24="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">6cd9b9c0-4756-11dc-bc8b-d7b5e2085d29</ns1:DelegationKey></ns24:ReferenceProperties><ns25:ReferenceParameters
xmlns:ns25="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:jobCredentialEndpoint><ns1:stagingCredentialEndpoint><ns26:Address
xmlns:ns26="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://192.168.31.54:8443/wsrf/services/DelegationService</ns26:Address><ns27:ReferenceProperties
xmlns:ns27="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">6cd9b9c0-4756-11dc-bc8b-d7b5e2085d29</ns1:DelegationKey></ns27:ReferenceProperties><ns28:ReferenceParameters
xmlns:ns28="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:stagingCredentialEndpoint><ns1:executable>/bin/sh</ns1:executable><ns1:argument>-c</ns1:argument><ns1:argument>.
${GLOBUS_LOCATION}/etc/globus-user-env.sh &amp;
${GLOBUS_LOCATION}/bin/gsi-tunnel -l -protection integrity -streams 1
-rendezvous-cmd ${GLOBUS_LOCATION}/bin/wsrf-rendezvous-client -rendezvous-epr
$GLOBUS_GRAM_MULTIJOB_HANDLE</ns1:argument><ns1:environment><ns1:name>PATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/bin:${GLOBUS_LOCATION}/sbin:/usr/local/bin:/bin:/usr/bin</ns1:value></ns1:environment><ns1:environment><ns1:name>LD_LIBRARY_PATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value></ns1:environment><ns1:environment><ns1:name>LIBPATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value></ns1:environment><ns1:stdout>${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-gsiTunnelListener.out</ns1:stdout><ns1:stderr>${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-gsiTunnelListener.err</ns1:stderr></ns1:job></ns1:job>

------- Comment #6 From Patrick Doran 2007-08-10 13:32:38 -------

2007-08-10 10:32:53,034 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:184] servicePath=ManagedJobFactoryService
2007-08-10 10:32:53,035 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:212] createManagedJob() called...
Caller ID:
/O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=Jini
Looked up local user ID: jini
2007-08-10 10:32:53,035 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:220] received a multi-job RSL
2007-08-10 10:32:53,037 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:274] Managed Job Service Path:
ManagedMultiJobService
2007-08-10 10:32:53,038 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:289] at create()
2007-08-10 10:32:53,053 DEBUG utils.PersistenceHelper
[ServiceThread-22,load:138] loading resource
org.globus.exec.service.multi.PersistentManagedMultiJobResource@4ed067 of key
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:53,054 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:305] JobID Specified, but not a duplicate
job id
2007-08-10 10:32:53,058 DEBUG utils.PersistenceHelper
[ServiceThread-22,load:138] loading resource
org.globus.exec.service.multi.PersistentManagedMultiJobResource@542394 of key
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:53,058 DEBUG multi.ManagedMultiJobHome
[ServiceThread-22,create:198] new resource being created
2007-08-10 10:32:53,072 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,initialize:135] Entering initialize()
2007-08-10 10:32:53,090 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,initSecurity:176] setting resource securty grid map...
Subject:
/O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=Jini
Local user ID: jini
2007-08-10 10:32:53,095 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,initialize:149] Leaving initialize()
2007-08-10 10:32:53,096 DEBUG multi.ManagedMultiJobHome
[ServiceThread-22,create:218] Created ManagedMultiJobResource with key value
f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:53,098 DEBUG utils.PersistenceHelper
[ServiceThread-22,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:53,099 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-22,setResourceDatum:146] Setting resource datum topicListener to
value [Lorg.globus.exec.generated.TopicListenerDescriptionType;@171ba6
2007-08-10 10:32:53,120 DEBUG utils.PersistenceHelper
[ServiceThread-22,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:53,121 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:329] at find()
2007-08-10 10:32:53,122 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:356] at start()
2007-08-10 10:32:53,122 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,start:217] Entering start()
2007-08-10 10:32:53,125 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:373] createManagedJob() exit
2007-08-10 10:32:53,125 DEBUG ManagedJobFactoryService.performance
[ServiceThread-22,stop:71] [createManagedJob][ServiceThread-22][142]
2007-08-10 10:32:53,126 DEBUG factory.ManagedJobFactoryService
[ServiceThread-22,createManagedJob:383] Entering createManaagedJob()
2007-08-10 10:32:53,136 INFO  client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,createJobEndpoint:958] <endTime
name="createManagedJob">1186759973136</endTime
2007-08-10 10:32:53,137 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,createJobEndpoint:969] Termination time
granted by the factory to the job resource: Sat Aug 11 10:32:52 CDT 2007
2007-08-10 10:32:53,137 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,createJobEndpoint:972] Current time seen
by the factory service on creation: Fri Aug 10 10:32:52 CDT 2007
2007-08-10 10:32:53,139 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,submit:483] Job Endpoint:
Address: https://192.168.31.172:8443/wsrf/services/ManagedMultiJobService
Reference property[0]:
<ns1:ResourceID
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job">f5a47e70-4756-11dc-b514-aa329bd042c4</ns1:ResourceID>

2007-08-10 10:32:53,178 DEBUG multi.PersistentManagedMultiJobResource
[Thread-207,run:68] Entering run()
2007-08-10 10:32:53,182 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[Thread-207,getJobCredential:413] job credential endpoint:
Address: https://192.168.31.172:8443/wsrf/services/DelegationService
Reference property[0]:
<ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey>

2007-08-10 10:32:53,187 DEBUG utils.DelegatedCredential
[Thread-207,getDelegationKey:610] Pulled out DelegationKey:
f49c8450-4756-11dc-b513-aa329bd042c4
2007-08-10 10:32:53,189 DEBUG utils.DelegatedCredential
[Thread-207,getDelegatedCredential:152] delegated credential endpoint (BEFORE):
Address: https://192.168.31.172:8443/wsrf/services/DelegationService
Reference property[0]:
<ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey>

2007-08-10 10:32:53,190 DEBUG utils.DelegatedCredential
[Thread-207,getDelegationKey:610] Pulled out DelegationKey:
f49c8450-4756-11dc-b513-aa329bd042c4
2007-08-10 10:32:53,190 DEBUG DelegatedCredential.performance
[Thread-207,stop:71] [new DelegatedCredential()][Thread-207][1]
2007-08-10 10:32:53,191 DEBUG utils.DelegatedCredential
[Thread-207,getDelegatedCredential:169] delegated credential endpoint (AFTER):
Address: https://192.168.31.172:8443/wsrf/services/DelegationService
Reference property[0]:
<ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey>

------- Comment #7 From Patrick Doran 2007-08-10 13:33:07 -------

2007-08-10 10:32:53,194 DEBUG utils.DelegatedCredential
[Thread-207,setCredential:317] received a new credential:
subject    :
O=Grid,OU=GlobusTest,OU=simpleCA-fc4test.univa.com,OU=univa.com,CN=Jini,CN=1420646988,CN=273861558,CN=1167705615,CN=1248595743
issuer     :
O=Grid,OU=GlobusTest,OU=simpleCA-fc4test.univa.com,OU=univa.com,CN=Jini,CN=1420646988,CN=273861558,CN=1167705615
strength   : 1024 bits
timeleft   : 604567 sec
proxy type : Proxy draft compliant impersonation proxy
2007-08-10 10:32:53,301 DEBUG DelegatedCredential.performance
[Thread-207,stop:71]
[DelegationUtil.registerDelegationListener()][Thread-207][110]
2007-08-10 10:32:53,302 DEBUG utils.DelegatedCredential
[Thread-207,initialize:269] waiting to receive initial credential...
2007-08-10 10:32:53,302 DEBUG utils.DelegatedCredential
[Thread-207,initialize:275] done waiting...
2007-08-10 10:32:53,304 DEBUG DelegatedCredential.performance
[Thread-207,stop:71] [cred.initialize()][Thread-207][2]
2007-08-10 10:32:53,304 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[Thread-207,getJobCredential:429] Delegated Job Credential Object:
org.globus.exec.service.utils.DelegatedCredential@8ef6db
2007-08-10 10:32:53,304 DEBUG utils.DelegatedCredential
[Thread-207,getCredential:362] waiting to receive initial credential...
2007-08-10 10:32:53,304 DEBUG utils.DelegatedCredential
[Thread-207,getCredential:370] done waiting...
2007-08-10 10:32:53,310 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[Thread-207,getJobCredential:432] Using proxy with subject
/O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=Jini
2007-08-10 10:32:53,312 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJobs:314] Entering createSubJobs()
2007-08-10 10:32:53,313 DEBUG utils.JobDescriptionMap [Thread-207,<init>:49]
processing 29 properties...
2007-08-10 10:32:53,313 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property argument...
2007-08-10 10:32:53,314 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property count...
2007-08-10 10:32:53,314 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property directory...
2007-08-10 10:32:53,314 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property environment...
2007-08-10 10:32:53,315 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property executable...
2007-08-10 10:32:53,315 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property extensions...
2007-08-10 10:32:53,316 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property factoryEndpoint...
2007-08-10 10:32:53,316 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property fileCleanUp...
2007-08-10 10:32:53,316 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property fileStageIn...
2007-08-10 10:32:53,318 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property fileStageOut...
2007-08-10 10:32:53,318 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property holdState...
2007-08-10 10:32:53,318 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property hostCount...
2007-08-10 10:32:53,318 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property job...
2007-08-10 10:32:53,319 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property jobCredentialEndpoint...
2007-08-10 10:32:53,319 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property jobType...
2007-08-10 10:32:53,319 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property libraryPath...
2007-08-10 10:32:53,319 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property localUserId...
2007-08-10 10:32:53,320 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property maxCpuTime...
2007-08-10 10:32:53,320 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property maxMemory...
2007-08-10 10:32:53,320 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property maxTime...
2007-08-10 10:32:53,321 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property maxWallTime...
2007-08-10 10:32:53,321 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property minMemory...
2007-08-10 10:32:53,321 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property project...
2007-08-10 10:32:53,321 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property queue...
2007-08-10 10:32:53,322 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property stagingCredentialEndpoint...
2007-08-10 10:32:53,322 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property stderr...
2007-08-10 10:32:53,323 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property stdin...
2007-08-10 10:32:53,324 DEBUG utils.JobDescriptionMap [Thread-207,<init>:60]
processing property stdout...
2007-08-10 10:32:53,369 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJobs:336] Sub-Job RSL:
<ns1:job
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job/description"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns1:JobDescriptionType">
 <ns1:factoryEndpoint
xmlns:ns2="http://schemas.xmlsoap.org/ws/2004/03/addressing"
xsi:type="ns2:EndpointReferenceType">
  <ns2:Address
xsi:type="ns2:AttributedURI">https://jini-suse-ddm.univa.com:8443/wsrf/services/ManagedJobFactoryService</ns2:Address>
  <ns2:ReferenceProperties xsi:type="ns2:ReferencePropertiesType">
   <ns9:ResourceID xmlns:ns10="http://www.globus.org/foobar"
xmlns:ns9="http://www.globus.org/namespaces/2004/10/gram/job"
xsi:type="ns10:QueryExpressionDialect">Fork</ns9:ResourceID>
  </ns2:ReferenceProperties>
  <ns2:ReferenceParameters xsi:type="ns2:ReferenceParametersType"/>
 </ns1:factoryEndpoint>
 <ns1:jobCredentialEndpoint
xmlns:ns3="http://schemas.xmlsoap.org/ws/2004/03/addressing"
xsi:type="ns3:EndpointReferenceType">
  <ns3:Address
xsi:type="ns3:AttributedURI">https://192.168.31.172:8443/wsrf/services/DelegationService</ns3:Address>
  <ns3:ReferenceProperties xsi:type="ns3:ReferencePropertiesType">
   <ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey>
  </ns3:ReferenceProperties>
  <ns3:ReferenceParameters xsi:type="ns3:ReferenceParametersType"/>
 </ns1:jobCredentialEndpoint>
 <ns1:stagingCredentialEndpoint
xmlns:ns4="http://schemas.xmlsoap.org/ws/2004/03/addressing"
xsi:type="ns4:EndpointReferenceType">
  <ns4:Address
xsi:type="ns4:AttributedURI">https://192.168.31.172:8443/wsrf/services/DelegationService</ns4:Address>
  <ns4:ReferenceProperties xsi:type="ns4:ReferencePropertiesType">
   <ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey>
  </ns4:ReferenceProperties>
  <ns4:ReferenceParameters xsi:type="ns4:ReferenceParametersType"/>
 </ns1:stagingCredentialEndpoint>
 <ns1:executable xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">/bin/sh</ns1:executable>
 <ns1:argument xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">-c</ns1:argument>
 <ns1:argument xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">. ${GLOBUS_LOCATION}/etc/globus-user-env.sh &amp;
${GLOBUS_LOCATION}/opt/ddm_rsync/rsync --recursive --force --verbose --verbose
--log-format=__item:%i:%l:%n --times --partial-dir=.rsync-partial
--delay-updates --rsh='${GLOBUS_LOCATION}/bin/gsi-tunnel -debug -protection
integrity -rendezvous-cmd ${GLOBUS_LOCATION}/bin/wsrf-rendezvous-client
-rendezvous-epr $GLOBUS_GRAM_MULTIJOB_HANDLE'
vanadium.univa.com:/tmp/test-dir/TC-Trans-056/file03
/tmp/test-dir/TC-Fault-045</ns1:argument>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">PATH</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_LOCATION}/bin:${GLOBUS_LOCATION}/sbin:/usr/local/bin:/bin:/usr/bin</ns1:value>
 </ns1:environment>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">LD_LIBRARY_PATH</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value>
 </ns1:environment>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">LIBPATH</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value>
 </ns1:environment>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">GLOBUS_GRAM_MULTIJOB_HANDLE</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">https://192.168.31.172:8443/wsrf/services/ManagedMultiJobService?f5a47e70-4756-11dc-b514-aa329bd042c4</ns1:value>
 </ns1:environment>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">GLOBUS_GRAM_SUBJOB_RANK</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">0</ns1:value>
 </ns1:environment>
 <ns1:stdout xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-rsync.out</ns1:stdout>
 <ns1:stderr xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-rsync.err</ns1:stderr>
</ns1:job>
2007-08-10 10:32:53,371 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJob:520] Entering createSubJob()
2007-08-10 10:32:53,404 DEBUG utils.DelegatedCredential
[Thread-207,getCredential:362] waiting to receive initial credential...
2007-08-10 10:32:53,405 DEBUG utils.DelegatedCredential
[Thread-207,getCredential:370] done waiting...
2007-08-10 10:32:53,419 DEBUG multi.ManagedMultiJobResource
[Thread-207,setStubSecurity:1107] Found host and cert configuration.
2007-08-10 10:32:53,421 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJob:581] notification consumer endpoint: Address:
https://192.168.31.172:8443/wsrf/services/NotificationConsumerService
Reference property[0]:
<ns1:NotificationConsumerKey
xmlns:ns1="http://www.globus.org/namespaces/2004/06/core"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="xsd:string">f5ff96c0-4756-11dc-b514-aa329bd042c4</ns1:NotificationConsumerKey>

2007-08-10 10:32:53,422 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[Thread-207,setResourceDatum:146] Setting resource datum
notificationConsumerEndpoint to value Address:
https://192.168.31.172:8443/wsrf/services/NotificationConsumerService
Reference property[0]:
<ns1:NotificationConsumerKey
xmlns:ns1="http://www.globus.org/namespaces/2004/06/core"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="xsd:string">f5ff96c0-4756-11dc-b514-aa329bd042c4</ns1:NotificationConsumerKey>

2007-08-10 10:32:53,423 DEBUG utils.PersistenceHelper [Thread-207,store:82]
storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:53,423 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[Thread-207,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@1695e3e
2007-08-10 10:32:53,439 DEBUG utils.PersistenceHelper [Thread-207,store:121]
done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:53,598 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:83] Entering createManaagedJob()
2007-08-10 10:32:53,599 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:105] setting job resource termination time
to null i.e. infinite
2007-08-10 10:32:53,646 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:160] received RSL :
<ns1:job
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job/description"><ns1:factoryEndpoint><ns2:Address
xmlns:ns2="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://jini-suse-ddm.univa.com:8443/wsrf/services/ManagedJobFactoryService</ns2:Address><ns3:ReferenceProperties
xmlns:ns3="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns9:ResourceID
xmlns:ns10="http://www.globus.org/foobar"
xmlns:ns9="http://www.globus.org/namespaces/2004/10/gram/job"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns10:QueryExpressionDialect">Fork</ns9:ResourceID></ns3:ReferenceProperties><ns4:ReferenceParameters
xmlns:ns4="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:factoryEndpoint><ns1:jobCredentialEndpoint><ns5:Address
xmlns:ns5="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://192.168.31.172:8443/wsrf/services/DelegationService</ns5:Address><ns6:ReferenceProperties
xmlns:ns6="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey></ns6:ReferenceProperties><ns7:ReferenceParameters
xmlns:ns7="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:jobCredentialEndpoint><ns1:stagingCredentialEndpoint><ns8:Address
xmlns:ns8="http://schemas.xmlsoap.org/ws/2004/03/addressing">https://192.168.31.172:8443/wsrf/services/DelegationService</ns8:Address><ns9:ReferenceProperties
xmlns:ns9="http://schemas.xmlsoap.org/ws/2004/03/addressing"><ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey></ns9:ReferenceProperties><ns10:ReferenceParameters
xmlns:ns10="http://schemas.xmlsoap.org/ws/2004/03/addressing"/></ns1:stagingCredentialEndpoint><ns1:executable>/bin/sh</ns1:executable><ns1:argument>-c</ns1:argument><ns1:argument>.
${GLOBUS_LOCATION}/etc/globus-user-env.sh &amp;
${GLOBUS_LOCATION}/opt/ddm_rsync/rsync --recursive --force --verbose --verbose
--log-format=__item:%i:%l:%n --times --partial-dir=.rsync-partial
--delay-updates --rsh='${GLOBUS_LOCATION}/bin/gsi-tunnel -debug -protection
integrity -rendezvous-cmd ${GLOBUS_LOCATION}/bin/wsrf-rendezvous-client
-rendezvous-epr $GLOBUS_GRAM_MULTIJOB_HANDLE'
vanadium.univa.com:/tmp/test-dir/TC-Trans-056/file03
/tmp/test-dir/TC-Fault-045</ns1:argument><ns1:environment><ns1:name>PATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/bin:${GLOBUS_LOCATION}/sbin:/usr/local/bin:/bin:/usr/bin</ns1:value></ns1:environment><ns1:environment><ns1:name>LD_LIBRARY_PATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value></ns1:environment><ns1:environment><ns1:name>LIBPATH</ns1:name><ns1:value>${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value></ns1:environment><ns1:environment><ns1:name>GLOBUS_GRAM_MULTIJOB_HANDLE</ns1:name><ns1:value>https://192.168.31.172:8443/wsrf/services/ManagedMultiJobService?f5a47e70-4756-11dc-b514-aa329bd042c4</ns1:value></ns1:environment><ns1:environment><ns1:name>GLOBUS_GRAM_SUBJOB_RANK</ns1:name><ns1:value>0</ns1:value></ns1:environment><ns1:stdout>${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-rsync.out</ns1:stdout><ns1:stderr>${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-rsync.err</ns1:stderr></ns1:job>
2007-08-10 10:32:53,648 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:184] servicePath=ManagedJobFactoryService
2007-08-10 10:32:53,648 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:212] createManagedJob() called...
Caller ID:
/O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=Jini
Looked up local user ID: jini
2007-08-10 10:32:53,650 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:224] received a single-job RSL
2007-08-10 10:32:53,650 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:274] Managed Job Service Path:
ManagedExecutableJobService
2007-08-10 10:32:53,653 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:289] at create()
2007-08-10 10:32:53,654 DEBUG utils.PersistenceHelper
[ServiceThread-23,load:138] loading resource
org.globus.exec.service.exec.PersistentManagedExecutableJobResource@195671e of
key
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:53,655 DEBUG exec.ManagedExecutableJobHome
[ServiceThread-23,create:273] new resource being created
2007-08-10 10:32:53,659 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,getJobCredential:413] job credential endpoint:
Address: https://192.168.31.172:8443/wsrf/services/DelegationService
Reference property[0]:
<ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey>

2007-08-10 10:32:53,660 DEBUG utils.DelegatedCredential
[ServiceThread-23,getDelegationKey:610] Pulled out DelegationKey:
f49c8450-4756-11dc-b513-aa329bd042c4
2007-08-10 10:32:53,661 DEBUG utils.DelegatedCredential
[ServiceThread-23,getDelegatedCredential:141] userProxFile:
/home/jini/.globus/gram_job_proxy_f49c8450-4756-11dc-b513-aa329bd042c4
2007-08-10 10:32:53,667 DEBUG utils.UserProxyCreator [ServiceThread-23,run:72]
Creating job user proxy.
2007-08-10 10:32:53,670 DEBUG utils.GlobusShToolsProperties
[ServiceThread-23,getInstance:43] entering getInstance()
2007-08-10 10:32:53,670 DEBUG utils.GlobusShToolsProperties
[ServiceThread-23,getInstance:75] leaving getInstance()
2007-08-10 10:32:53,672 DEBUG utils.AuthorizationHelper
[ServiceThread-23,isAuthorizationGridmap:70] Entering/Exiting
isAuthorizationGridmap()
2007-08-10 10:32:53,673 DEBUG utils.UserProxyCreator [ServiceThread-23,run:147]
Executing command:
/usr/bin/sudo -u jini -S
/usr/local/globus-4.0.3/libexec/globus-gridmap-and-execute -g
/etc/grid-security/grid-mapfile
/usr/local/globus-4.0.3/libexec/globus-gram-local-proxy-tool
/usr/local/globus-4.0.3 -write
/home/jini/.globus/gram_job_proxy_f49c8450-4756-11dc-b513-aa329bd042c4
2007-08-10 10:32:53,953 DEBUG UserProxyCreator.performance
[ServiceThread-23,stop:71] [createCertificate()][ServiceThread-23][86]
2007-08-10 10:32:54,216 DEBUG UserProxyCreator.performance
[ServiceThread-23,stop:71] [write user proxy][ServiceThread-23][349]
2007-08-10 10:32:54,219 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,getJobCredential:429] Delegated Job Credential Object:
org.globus.exec.service.utils.DelegatedCredential@8ef6db
2007-08-10 10:32:54,220 DEBUG utils.DelegatedCredential
[ServiceThread-23,getCredential:362] waiting to receive initial credential...
2007-08-10 10:32:54,222 DEBUG utils.DelegatedCredential
[ServiceThread-23,getCredential:370] done waiting...
2007-08-10 10:32:54,242 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,getJobCredential:432] Using proxy with subject
/O=Grid/OU=GlobusTest/OU=simpleCA-fc4test.univa.com/OU=univa.com/CN=Jini
2007-08-10 10:32:54,260 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,resolveVariables:771] Entering resolveVariables()
2007-08-10 10:32:54,268 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,resolveVariables:1276] Leaving resolveVariables()
2007-08-10 10:32:54,271 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:49] processing 28 properties...
2007-08-10 10:32:54,273 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property argument...
2007-08-10 10:32:54,275 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property count...
2007-08-10 10:32:54,277 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property directory...
2007-08-10 10:32:54,280 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property environment...
2007-08-10 10:32:54,282 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property executable...
2007-08-10 10:32:54,284 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property extensions...
2007-08-10 10:32:54,286 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property factoryEndpoint...
2007-08-10 10:32:54,288 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property fileCleanUp...
2007-08-10 10:32:54,292 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property fileStageIn...
2007-08-10 10:32:54,293 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property fileStageOut...
2007-08-10 10:32:54,296 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property holdState...
2007-08-10 10:32:54,298 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property hostCount...
2007-08-10 10:32:54,300 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property jobCredentialEndpoint...
2007-08-10 10:32:54,302 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property jobType...
2007-08-10 10:32:54,304 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property libraryPath...
2007-08-10 10:32:54,306 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property localUserId...
2007-08-10 10:32:54,308 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property maxCpuTime...
2007-08-10 10:32:54,310 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property maxMemory...
2007-08-10 10:32:54,313 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property maxTime...
2007-08-10 10:32:54,315 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property maxWallTime...
2007-08-10 10:32:54,317 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property minMemory...
2007-08-10 10:32:54,319 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property project...
2007-08-10 10:32:54,321 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property queue...
2007-08-10 10:32:54,323 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property stagingCredentialEndpoint...
2007-08-10 10:32:54,325 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property stderr...
2007-08-10 10:32:54,328 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property stdin...
2007-08-10 10:32:54,330 DEBUG utils.JobDescriptionMap
[ServiceThread-23,<init>:60] processing property stdout...

------- Comment #8 From Patrick Doran 2007-08-10 13:33:36 -------

2007-08-10 10:32:54,333 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
directory/directory
2007-08-10 10:32:54,334 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute directory is of type
java.lang.String
2007-08-10 10:32:54,335 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
maxCpuTime/maxcputime
2007-08-10 10:32:54,337 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name condorOs/condoros
2007-08-10 10:32:54,339 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute condoros is of type
java.lang.String
2007-08-10 10:32:54,341 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
fileStageIn/filestagein
2007-08-10 10:32:54,343 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
maxMemory/maxmemory
2007-08-10 10:32:54,344 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
minMemory/minmemory
2007-08-10 10:32:54,345 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
condorArch/condorarch
2007-08-10 10:32:54,348 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute condorarch is of type
java.lang.String
2007-08-10 10:32:54,350 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name stderr/stderr
2007-08-10 10:32:54,352 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute stderr is of type
java.lang.String
2007-08-10 10:32:54,353 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
environment/environment
2007-08-10 10:32:54,354 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute environment is of type
[Lorg.globus.exec.generated.NameValuePairType;
2007-08-10 10:32:54,356 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:180] Attribute environment has component type
org.globus.exec.generated.NameValuePairType
2007-08-10 10:32:54,358 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:186] Attribute environment being processed as
NameValuePairType[]
2007-08-10 10:32:54,361 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
extensions/extensions
2007-08-10 10:32:54,362 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
jobCredentialEndpoint/jobcredentialendpoint
2007-08-10 10:32:54,364 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute jobcredentialendpoint is of type
org.apache.axis.message.addressing.EndpointReferenceType
2007-08-10 10:32:54,369 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
hostCount/hostcount
2007-08-10 10:32:54,371 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
xmlextensions/xmlextensions
2007-08-10 10:32:54,374 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute xmlextensions is of type
java.lang.String
2007-08-10 10:32:54,390 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name queue/queue
2007-08-10 10:32:54,393 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
localUserId/localuserid
2007-08-10 10:32:54,394 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
arguments/arguments
2007-08-10 10:32:54,397 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute arguments is of type
[Ljava.lang.String;
2007-08-10 10:32:54,411 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:180] Attribute arguments has component type
java.lang.String
2007-08-10 10:32:54,413 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
fileStageOut/filestageout
2007-08-10 10:32:54,414 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
executable/executable
2007-08-10 10:32:54,417 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute executable is of type
java.lang.String
2007-08-10 10:32:54,418 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
stagingCredentialEndpoint/stagingcredentialendpoint
2007-08-10 10:32:54,421 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute stagingcredentialendpoint is of
type org.apache.axis.message.addressing.EndpointReferenceType
2007-08-10 10:32:54,435 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
factoryEndpoint/factoryendpoint
2007-08-10 10:32:54,436 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute factoryendpoint is of type
org.apache.axis.message.addressing.EndpointReferenceType
2007-08-10 10:32:54,438 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
holdState/holdstate
2007-08-10 10:32:54,438 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name stdin/stdin
2007-08-10 10:32:54,439 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:151] appending stdin = /dev/null
2007-08-10 10:32:54,439 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
fileCleanUp/filecleanup
2007-08-10 10:32:54,440 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name jobdir/jobdir
2007-08-10 10:32:54,442 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute jobdir is of type
java.lang.String
2007-08-10 10:32:54,442 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name jobType/jobtype
2007-08-10 10:32:54,443 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name stdout/stdout
2007-08-10 10:32:54,443 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute stdout is of type
java.lang.String
2007-08-10 10:32:54,444 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
maxWallTime/maxwalltime
2007-08-10 10:32:54,445 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name project/project
2007-08-10 10:32:54,446 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name count/count
2007-08-10 10:32:54,448 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute count is of type
org.apache.axis.types.PositiveInteger
2007-08-10 10:32:54,449 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
libraryPath/librarypath
2007-08-10 10:32:54,451 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name
useForkStarter/useforkstarter
2007-08-10 10:32:54,451 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:172] Attribute useforkstarter is of type
java.lang.String
2007-08-10 10:32:54,452 DEBUG exec.PerlJobDescription
[ServiceThread-23,toPerlString:130] processing attribute name maxTime/maxtime
2007-08-10 10:32:54,452 DEBUG exec.ManagedExecutableJobHome
[ServiceThread-23,create:311] Created ManagedExecutableJobResource with key
value f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,453 DEBUG utils.PersistenceHelper
[ServiceThread-23,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:54,454 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,setResourceDatum:146] Setting resource datum topicListener to
value [Lorg.globus.exec.generated.TopicListenerDescriptionType;@1e0482b
2007-08-10 10:32:54,460 DEBUG exec.PersistentManagedExecutableJobResource
[ServiceThread-23,setDirty:308] setting dirty flag to false
2007-08-10 10:32:54,461 DEBUG utils.PersistenceHelper
[ServiceThread-23,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,462 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:329] at find()
2007-08-10 10:32:54,463 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:345] at subscribe()
2007-08-10 10:32:54,478 DEBUG utils.PersistenceHelper
[ServiceThread-23,store:77] Dirty flag not set: resource will not be stored
2007-08-10 10:32:54,479 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:356] at start()
2007-08-10 10:32:54,480 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,getInternalState:1661] getting resource datum internalState
2007-08-10 10:32:54,480 DEBUG exec.RunQueue [ServiceThread-23,getInstance:102]
Getting RunQueue instance #5
2007-08-10 10:32:54,481 DEBUG exec.RunQueue [ServiceThread-23,getInstance:106]
Returning RunQueue instance: org.globus.exec.service.exec.RunQueue@b5e041
2007-08-10 10:32:54,482 DEBUG exec.RunQueue [ServiceThread-23,add:62] adding
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
to queue.
2007-08-10 10:32:54,483 DEBUG exec.RunQueue [ServiceThread-23,add:69]
RunQueue Other Graph: *
2007-08-10 10:32:54,483 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:373] createManagedJob() exit
2007-08-10 10:32:54,484 DEBUG ManagedJobFactoryService.performance
[ServiceThread-23,stop:71] [createManagedJob][ServiceThread-23][885]
2007-08-10 10:32:54,484 DEBUG factory.ManagedJobFactoryService
[ServiceThread-23,createManagedJob:383] Entering createManaagedJob()
2007-08-10 10:32:54,485 DEBUG exec.RunQueue [RunQueue Other-1,remove:84]
removing
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
from queue.
2007-08-10 10:32:54,496 DEBUG exec.RunQueue [RunQueue Other-1,remove:91]
RunQueue Other Graph:
2007-08-10 10:32:54,496 DEBUG exec.RunThread [RunQueue Other-1,run:88]
Processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,496 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getInternalState:1661] getting resource datum internalState
2007-08-10 10:32:54,496 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum canceled
2007-08-10 10:32:54,497 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum userCancelRequested
2007-08-10 10:32:54,497 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum systemCancelRequested
2007-08-10 10:32:54,497 DEBUG exec.StateMachine [RunQueue
Other-1,processState:305] [resourceKey:f6232450-4756-11dc-b514-aa329bd042c4]
processing internal state None
2007-08-10 10:32:54,497 DEBUG exec.StateMachine [RunQueue
Other-1,processState:313] [resourceKey:f6232450-4756-11dc-b514-aa329bd042c4]
------------------------------------------------------
PROCESSING INTERNAL STATE:  -- None --
------------------------------------------------------
2007-08-10 10:32:54,498 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum notifiedJobData
2007-08-10 10:32:54,498 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,setResourceDatum:146] Setting resource datum started to value true
2007-08-10 10:32:54,498 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to true
2007-08-10 10:32:54,499 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:54,499 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@14b85a7
2007-08-10 10:32:54,513 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to false
2007-08-10 10:32:54,514 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,514 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum holdState
2007-08-10 10:32:54,514 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,setInternalState:1690] Setting resource datum internalState to value
Start
2007-08-10 10:32:54,515 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to true
2007-08-10 10:32:54,515 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:54,516 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@9b5e7e
2007-08-10 10:32:54,525 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to false
2007-08-10 10:32:54,525 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,526 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getInternalState:1661] getting resource datum internalState
2007-08-10 10:32:54,526 DEBUG exec.RunQueue [RunQueue Other-1,getInstance:102]
Getting RunQueue instance #5
2007-08-10 10:32:54,526 DEBUG exec.RunQueue [RunQueue Other-1,getInstance:106]
Returning RunQueue instance: org.globus.exec.service.exec.RunQueue@b5e041
2007-08-10 10:32:54,527 DEBUG exec.RunQueue [RunQueue Other-1,add:62] adding
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
to queue.
2007-08-10 10:32:54,527 DEBUG exec.RunQueue [RunQueue Other-1,add:69]
RunQueue Other Graph: *
2007-08-10 10:32:54,527 DEBUG StateMachine.performance [RunQueue
Other-1,stop:71] [processNoneState][RunQueue Other-1][29]
2007-08-10 10:32:54,528 DEBUG exec.RunThread [RunQueue Other-1,run:104]
processState returned
2007-08-10 10:32:54,529 DEBUG exec.RunThread [RunQueue Other-1,run:109] Done
processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,529 DEBUG exec.RunQueue [RunQueue Other-1,remove:84]
removing
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
from queue.
2007-08-10 10:32:54,529 DEBUG exec.RunQueue [RunQueue Other-1,remove:91]
RunQueue Other Graph:
2007-08-10 10:32:54,529 DEBUG exec.RunThread [RunQueue Other-1,run:88]
Processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,529 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getInternalState:1661] getting resource datum internalState
2007-08-10 10:32:54,530 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum canceled
2007-08-10 10:32:54,530 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum userCancelRequested
2007-08-10 10:32:54,530 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum systemCancelRequested
2007-08-10 10:32:54,530 DEBUG exec.StateMachine [RunQueue
Other-1,processState:305] [resourceKey:f6232450-4756-11dc-b514-aa329bd042c4]
processing internal state Start
2007-08-10 10:32:54,506 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJob:632] Leaving createSubJob()
2007-08-10 10:32:54,551 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJobs:336] Sub-Job RSL:
<ns1:job
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job/description"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns1:JobDescriptionType">
 <ns1:factoryEndpoint
xmlns:ns2="http://schemas.xmlsoap.org/ws/2004/03/addressing"
xsi:type="ns2:EndpointReferenceType">
  <ns2:Address
xsi:type="ns2:AttributedURI">https://vanadium.univa.com:8443/wsrf/services/ManagedJobFactoryService</ns2:Address>
  <ns2:ReferenceProperties xsi:type="ns2:ReferencePropertiesType">
   <ns14:ResourceID
xmlns:ns14="http://www.globus.org/namespaces/2004/10/gram/job"
xmlns:ns15="http://www.globus.org/foobar"
xsi:type="ns15:QueryExpressionDialect">Fork</ns14:ResourceID>
  </ns2:ReferenceProperties>
  <ns2:ReferenceParameters xsi:type="ns2:ReferenceParametersType"/>
 </ns1:factoryEndpoint>
 <ns1:jobCredentialEndpoint
xmlns:ns3="http://schemas.xmlsoap.org/ws/2004/03/addressing"
xsi:type="ns3:EndpointReferenceType">
  <ns3:Address
xsi:type="ns3:AttributedURI">https://192.168.31.54:8443/wsrf/services/DelegationService</ns3:Address>
  <ns3:ReferenceProperties xsi:type="ns3:ReferencePropertiesType">
   <ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">6cd9b9c0-4756-11dc-bc8b-d7b5e2085d29</ns1:DelegationKey>
  </ns3:ReferenceProperties>
  <ns3:ReferenceParameters xsi:type="ns3:ReferenceParametersType"/>
 </ns1:jobCredentialEndpoint>
 <ns1:stagingCredentialEndpoint
xmlns:ns4="http://schemas.xmlsoap.org/ws/2004/03/addressing"
xsi:type="ns4:EndpointReferenceType">
  <ns4:Address
xsi:type="ns4:AttributedURI">https://192.168.31.54:8443/wsrf/services/DelegationService</ns4:Address>
  <ns4:ReferenceProperties xsi:type="ns4:ReferencePropertiesType">
   <ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">6cd9b9c0-4756-11dc-bc8b-d7b5e2085d29</ns1:DelegationKey>
  </ns4:ReferenceProperties>
  <ns4:ReferenceParameters xsi:type="ns4:ReferenceParametersType"/>
 </ns1:stagingCredentialEndpoint>
 <ns1:executable xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">/bin/sh</ns1:executable>
 <ns1:argument xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">-c</ns1:argument>
 <ns1:argument xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">. ${GLOBUS_LOCATION}/etc/globus-user-env.sh &amp;
${GLOBUS_LOCATION}/bin/gsi-tunnel -l -protection integrity -streams 1
-rendezvous-cmd ${GLOBUS_LOCATION}/bin/wsrf-rendezvous-client -rendezvous-epr
$GLOBUS_GRAM_MULTIJOB_HANDLE</ns1:argument>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">PATH</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_LOCATION}/bin:${GLOBUS_LOCATION}/sbin:/usr/local/bin:/bin:/usr/bin</ns1:value>
 </ns1:environment>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">LD_LIBRARY_PATH</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value>
 </ns1:environment>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">LIBPATH</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_LOCATION}/lib:/usr/lib:/lib:/usr/lib64:/lib64</ns1:value>
 </ns1:environment>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">GLOBUS_GRAM_MULTIJOB_HANDLE</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">https://192.168.31.172:8443/wsrf/services/ManagedMultiJobService?f5a47e70-4756-11dc-b514-aa329bd042c4</ns1:value>
 </ns1:environment>
 <ns1:environment xsi:type="ns1:NameValuePairType">
  <ns1:name xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">GLOBUS_GRAM_SUBJOB_RANK</ns1:name>
  <ns1:value xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">1</ns1:value>
 </ns1:environment>
 <ns1:stdout xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-gsiTunnelListener.out</ns1:stdout>
 <ns1:stderr xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xsi:type="xsd:string">${GLOBUS_USER_HOME}/f449d070-4756-11dc-b513-aa329bd042c4-gsiTunnelListener.err</ns1:stderr>
</ns1:job>
2007-08-10 10:32:54,552 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJob:520] Entering createSubJob()
2007-08-10 10:32:54,574 DEBUG utils.DelegatedCredential
[Thread-207,getCredential:362] waiting to receive initial credential...
2007-08-10 10:32:54,576 DEBUG utils.DelegatedCredential
[Thread-207,getCredential:370] done waiting...
2007-08-10 10:32:54,580 DEBUG multi.ManagedMultiJobResource
[Thread-207,setStubSecurity:1107] Found host and cert configuration.
2007-08-10 10:32:54,645 DEBUG exec.StateMachine [RunQueue
Other-1,processState:313] [resourceKey:f6232450-4756-11dc-b514-aa329bd042c4]

------- Comment #9 From Patrick Doran 2007-08-10 13:34:02 -------

------------------------------------------------------
PROCESSING INTERNAL STATE:  -- Start --
------------------------------------------------------
2007-08-10 10:32:54,678 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getResourceDatum:217] getting resource datum notifiedJobData
2007-08-10 10:32:54,680 INFO  exec.StateMachine [RunQueue
Other-1,logJobAccepted:3240] Job f6232450-4756-11dc-b514-aa329bd042c4 accepted
for local user 'jini'
2007-08-10 10:32:54,681 DEBUG exec.StateMachine [RunQueue
Other-1,processStartState:629]
[resourceKey:f6232450-4756-11dc-b514-aa329bd042c4] Skipping StageIn and going
straight to Submit
2007-08-10 10:32:54,682 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,setInternalState:1690] Setting resource datum internalState to value
Submit
2007-08-10 10:32:54,683 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to true
2007-08-10 10:32:54,684 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:54,725 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@58b5ff
2007-08-10 10:32:54,748 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Other-1,setDirty:308] setting dirty flag to false
2007-08-10 10:32:54,749 DEBUG utils.PersistenceHelper [RunQueue
Other-1,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,750 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Other-1,getInternalState:1661] getting resource datum internalState
2007-08-10 10:32:54,751 DEBUG exec.RunQueue [RunQueue Other-1,getInstance:102]
Getting RunQueue instance #1
2007-08-10 10:32:54,752 DEBUG exec.RunQueue [RunQueue Other-1,getInstance:106]
Returning RunQueue instance: org.globus.exec.service.exec.RunQueue@f65821
2007-08-10 10:32:54,753 DEBUG exec.RunQueue [RunQueue Other-1,add:62] adding
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
to queue.
2007-08-10 10:32:54,755 DEBUG exec.RunQueue [RunQueue Other-1,add:69]
RunQueue Submit Graph: *
2007-08-10 10:32:54,755 DEBUG StateMachine.performance [RunQueue
Other-1,stop:71] [processStartState][RunQueue Other-1][75]
2007-08-10 10:32:54,756 DEBUG exec.RunThread [RunQueue Other-1,run:104]
processState returned
2007-08-10 10:32:54,757 DEBUG exec.RunThread [RunQueue Other-1,run:109] Done
processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,758 DEBUG exec.RunQueue [RunQueue Submit-1,remove:84]
removing
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
from queue.
2007-08-10 10:32:54,758 DEBUG exec.RunQueue [RunQueue Submit-1,remove:91]
RunQueue Submit Graph:
2007-08-10 10:32:54,759 DEBUG exec.RunThread [RunQueue Submit-1,run:88]
Processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:54,760 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getInternalState:1661] getting resource datum internalState
2007-08-10 10:32:54,761 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum canceled
2007-08-10 10:32:54,762 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum userCancelRequested
2007-08-10 10:32:54,762 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum systemCancelRequested
2007-08-10 10:32:54,763 DEBUG exec.StateMachine [RunQueue
Submit-1,processState:305] [resourceKey:f6232450-4756-11dc-b514-aa329bd042c4]
processing internal state Submit
2007-08-10 10:32:54,764 DEBUG exec.StateMachine [RunQueue
Submit-1,processState:313] [resourceKey:f6232450-4756-11dc-b514-aa329bd042c4]
------------------------------------------------------
PROCESSING INTERNAL STATE:  -- Submit --
------------------------------------------------------
2007-08-10 10:32:54,765 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum notifiedJobData
2007-08-10 10:32:54,766 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum holdState
2007-08-10 10:32:54,767 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum localResourceManager
2007-08-10 10:32:54,769 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name directory/directory
2007-08-10 10:32:54,769 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute directory is of type java.lang.String
2007-08-10 10:32:54,771 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name maxCpuTime/maxcputime
2007-08-10 10:32:54,772 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name condorOs/condoros
2007-08-10 10:32:54,773 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute condoros is of type java.lang.String
2007-08-10 10:32:54,774 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name fileStageIn/filestagein
2007-08-10 10:32:54,775 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name maxMemory/maxmemory
2007-08-10 10:32:54,776 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name minMemory/minmemory
2007-08-10 10:32:54,777 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name
useforkstarter/useforkstarter
2007-08-10 10:32:54,778 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute useforkstarter is of type java.lang.String
2007-08-10 10:32:54,779 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name condorArch/condorarch
2007-08-10 10:32:54,780 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute condorarch is of type java.lang.String
2007-08-10 10:32:54,781 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name stderr/stderr
2007-08-10 10:32:54,783 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute stderr is of type java.lang.String
2007-08-10 10:32:54,783 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name environment/environment
2007-08-10 10:32:54,784 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute environment is of type
[Lorg.globus.exec.generated.NameValuePairType;
2007-08-10 10:32:54,785 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:180] Attribute environment has component type
org.globus.exec.generated.NameValuePairType
2007-08-10 10:32:54,786 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:186] Attribute environment being processed as
NameValuePairType[]
2007-08-10 10:32:54,787 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name extensions/extensions
2007-08-10 10:32:54,788 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name
jobCredentialEndpoint/jobcredentialendpoint
2007-08-10 10:32:54,788 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute jobcredentialendpoint is of type
org.apache.axis.message.addressing.EndpointReferenceType
2007-08-10 10:32:54,793 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name hostCount/hostcount
2007-08-10 10:32:54,794 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name
xmlextensions/xmlextensions
2007-08-10 10:32:54,796 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute xmlextensions is of type java.lang.String
2007-08-10 10:32:54,798 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name queue/queue
2007-08-10 10:32:54,799 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name localUserId/localuserid
2007-08-10 10:32:54,800 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name arguments/arguments
2007-08-10 10:32:54,801 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute arguments is of type [Ljava.lang.String;
2007-08-10 10:32:54,802 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:180] Attribute arguments has component type
java.lang.String
2007-08-10 10:32:54,803 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name fileStageOut/filestageout
2007-08-10 10:32:54,805 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name executable/executable
2007-08-10 10:32:54,806 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute executable is of type java.lang.String
2007-08-10 10:32:54,807 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name
stagingCredentialEndpoint/stagingcredentialendpoint
2007-08-10 10:32:54,809 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute stagingcredentialendpoint is of type
org.apache.axis.message.addressing.EndpointReferenceType
2007-08-10 10:32:54,812 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name
factoryEndpoint/factoryendpoint
2007-08-10 10:32:54,840 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute factoryendpoint is of type
org.apache.axis.message.addressing.EndpointReferenceType
2007-08-10 10:32:54,845 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name holdState/holdstate
2007-08-10 10:32:54,848 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name stdin/stdin
2007-08-10 10:32:54,848 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:151] appending stdin = /dev/null
2007-08-10 10:32:54,849 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name fileCleanUp/filecleanup
2007-08-10 10:32:54,850 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name
expand_globus_home/expandglobushome
2007-08-10 10:32:54,851 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute expandglobushome is of type
java.lang.String
2007-08-10 10:32:54,851 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name jobdir/jobdir
2007-08-10 10:32:54,852 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute jobdir is of type java.lang.String
2007-08-10 10:32:54,853 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name jobType/jobtype
2007-08-10 10:32:54,854 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name stdout/stdout
2007-08-10 10:32:54,855 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute stdout is of type java.lang.String
2007-08-10 10:32:54,856 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name maxWallTime/maxwalltime
2007-08-10 10:32:54,857 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name project/project
2007-08-10 10:32:54,858 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name
expand_globus_location/expandglobuslocation
2007-08-10 10:32:54,859 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute expandglobuslocation is of type
java.lang.String
2007-08-10 10:32:54,860 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name count/count
2007-08-10 10:32:54,861 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute count is of type
org.apache.axis.types.PositiveInteger
2007-08-10 10:32:54,862 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name libraryPath/librarypath
2007-08-10 10:32:54,863 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name
useForkStarter/useforkstarter
2007-08-10 10:32:54,864 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:172] Attribute useforkstarter is of type java.lang.String
2007-08-10 10:32:54,865 DEBUG exec.PerlJobDescription [RunQueue
Submit-1,toPerlString:130] processing attribute name maxTime/maxtime
2007-08-10 10:32:54,866 DEBUG exec.StateMachine [RunQueue
Submit-1,runScript:2915] Perl Job Description: $description = {
    directory => [ '/home/jini' ],
    condoros => [ 'LINUX' ],
    useforkstarter => [ '1' ],
    condorarch => [ 'INTEL' ],
    stderr => [ '/home/jini/f449d070-4756-11dc-b513-aa329bd042c4-rsync.err' ],
    environment => [ [ 'PATH',
'/usr/local/globus-4.0.3/bin:/usr/local/globus-4.0.3/sbin:/usr/local/bin:/bin:/usr/bin'
], [ 'LD_LIBRARY_PATH',
'/usr/local/globus-4.0.3/lib:/usr/lib:/lib:/usr/lib64:/lib64' ], [ 'LIBPATH',
'/usr/local/globus-4.0.3/lib:/usr/lib:/lib:/usr/lib64:/lib64' ], [
'GLOBUS_GRAM_MULTIJOB_HANDLE',
'https://192.168.31.172:8443/wsrf/services/ManagedMultiJobService?f5a47e70-4756-11dc-b514-aa329bd042c4'
], [ 'GLOBUS_GRAM_SUBJOB_RANK', '0' ], [ 'GLOBUS_LOCATION',
'/usr/local/globus-4.0.3' ], [ 'X509_CERT_DIR',
'/etc/grid-security/certificates' ], [ 'X509_USER_PROXY',
'/home/jini/.globus/gram_job_proxy_f49c8450-4756-11dc-b513-aa329bd042c4' ], [
'X509_USER_CERT',
'/home/jini/.globus/gram_job_proxy_f49c8450-4756-11dc-b513-aa329bd042c4' ], [
'X509_USER_KEY',
'/home/jini/.globus/gram_job_proxy_f49c8450-4756-11dc-b513-aa329bd042c4' ], [
'HOME', '/home/jini' ], [ 'LOGNAME', 'jini' ], [ 'SCRATCH_DIRECTORY',
'/home/jini/.globus/scratch' ], [ 'JAVA_HOME', '/usr/local/bin/java/jre' ], [
'GLOBUS_GRAM_JOB_HANDLE',
'https://192.168.31.172:8443/wsrf/services/ManagedExecutableJobService?f6232450-4756-11dc-b514-aa329bd042c4'
],  ],
    jobcredentialendpoint => [ 'Address:
https://192.168.31.172:8443/wsrf/services/DelegationService
Reference property[0]:
<ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey>
' ],
    xmlextensions => [ '1' ],
    arguments => [ '-c', '. /usr/local/globus-4.0.3/etc/globus-user-env.sh &
/usr/local/globus-4.0.3/opt/ddm_rsync/rsync --recursive --force --verbose
--verbose --log-format=__item:%i:%l:%n --times --partial-dir=.rsync-partial
--delay-updates --rsh=\'/usr/local/globus-4.0.3/bin/gsi-tunnel -debug
-protection integrity -rendezvous-cmd
/usr/local/globus-4.0.3/bin/wsrf-rendezvous-client -rendezvous-epr
$GLOBUS_GRAM_MULTIJOB_HANDLE\'
vanadium.univa.com:/tmp/test-dir/TC-Trans-056/file03
/tmp/test-dir/TC-Fault-045' ],
    executable => [ '/bin/sh' ],
    stagingcredentialendpoint => [ 'Address:
https://192.168.31.172:8443/wsrf/services/DelegationService
Reference property[0]:
<ns1:DelegationKey
xmlns:ns1="http://www.globus.org/08/2004/delegationService">f49c8450-4756-11dc-b513-aa329bd042c4</ns1:DelegationKey>
' ],
    factoryendpoint => [ 'Address:
https://jini-suse-ddm.univa.com:8443/wsrf/services/ManagedJobFactoryService
Reference property[0]:
<ns9:ResourceID xmlns:ns10="http://www.globus.org/foobar"
xmlns:ns9="http://www.globus.org/namespaces/2004/10/gram/job"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:type="ns10:QueryExpressionDialect">Fork</ns9:ResourceID>
' ],
    stdin => [ '/dev/null' ],
    expandglobushome => [ '1' ],
    jobdir => [ '/home/jini/.globus/f6232450-4756-11dc-b514-aa329bd042c4' ],
    jobtype => [ 'multiple' ],
    stdout => [ '/home/jini/f449d070-4756-11dc-b513-aa329bd042c4-rsync.out' ],
    expandglobuslocation => [ '1' ],
    count => [ '1' ],
    useforkstarter => [ '1' ],
};

2007-08-10 10:32:54,868 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum localResourceManager
2007-08-10 10:32:55,008 DEBUG utils.GlobusShToolsProperties [RunQueue
Submit-1,getInstance:43] entering getInstance()
2007-08-10 10:32:55,011 DEBUG utils.GlobusShToolsProperties [RunQueue
Submit-1,getInstance:75] leaving getInstance()
2007-08-10 10:32:55,012 DEBUG utils.AuthorizationHelper [RunQueue
Submit-1,isAuthorizationGridmap:70] Entering/Exiting isAuthorizationGridmap()
2007-08-10 10:32:55,015 DEBUG exec.JobManagerScript [Thread-208,run:208]
Executing command:
/usr/bin/sudo -H -u jini -S
/usr/local/globus-4.0.3/libexec/globus-gridmap-and-execute -g
/etc/grid-security/grid-mapfile
/usr/local/globus-4.0.3/libexec/globus-job-manager-script.pl -m fork -f
/usr/local/globus-4.0.3/tmp/gram_job_mgr19560.tmp -c submit
2007-08-10 10:32:55,221 DEBUG exec.JobManagerScript [Thread-208,run:225] first
line: GRAM_SCRIPT_JOB_ID:f711ffda-4756-11dc-b4e6-000c297b4f57:12969
2007-08-10 10:32:55,222 DEBUG exec.JobManagerScript [Thread-208,run:240]
Received local job ID f711ffda-4756-11dc-b4e6-000c297b4f57:12969
2007-08-10 10:32:55,226 DEBUG exec.JobManagerScript [Thread-208,run:335]
failure message: null
2007-08-10 10:32:55,226 DEBUG exec.JobManagerScript [Thread-208,setDone:345]
script is done, setting done flag
2007-08-10 10:32:55,227 DEBUG exec.StateMachine [RunQueue
Submit-1,processSubmitState:1188] script return code: 0
2007-08-10 10:32:55,227 DEBUG exec.StateMachine [RunQueue
Submit-1,processSubmitState:1220] script returned job state: Active
2007-08-10 10:32:55,228 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum localJobId
2007-08-10 10:32:55,228 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,getResourceDatum:217] getting resource datum localJobState
2007-08-10 10:32:55,228 DEBUG exec.StateMachine [RunQueue
Submit-1,setLocalJobId:2973] Saving local job ID
f711ffda-4756-11dc-b4e6-000c297b4f57:12969
2007-08-10 10:32:55,229 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,setResourceDatum:146] Setting resource datum localJobId to value
[Ljava.lang.String;@1489f6
2007-08-10 10:32:55,229 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-1,setDirty:308] setting dirty flag to true
2007-08-10 10:32:55,230 DEBUG utils.PersistenceHelper [RunQueue
Submit-1,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:55,230 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@6dadf0
2007-08-10 10:32:55,239 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-1,setDirty:308] setting dirty flag to false
2007-08-10 10:32:55,240 DEBUG utils.PersistenceHelper [RunQueue
Submit-1,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:55,240 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,setResourceDatum:146] Setting resource datum localJobState to value
[Lorg.globus.exec.generated.StateEnumeration;@b66adc
2007-08-10 10:32:55,240 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-1,setDirty:308] setting dirty flag to true
2007-08-10 10:32:55,241 DEBUG utils.PersistenceHelper [RunQueue
Submit-1,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:55,241 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@219702
2007-08-10 10:32:55,248 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-1,setDirty:308] setting dirty flag to false
2007-08-10 10:32:55,249 DEBUG utils.PersistenceHelper [RunQueue
Submit-1,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:55,250 DEBUG exec.StateMachine [RunQueue
Submit-1,processSubmitState:1240] Subscribing job
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
to SEG events for local job ID f711ffda-4756-11dc-b4e6-000c297b4f57:12969
2007-08-10 10:32:55,250 DEBUG utils.JobStateMonitorSubscriptionManager
[RunQueue Submit-1,add:103] adding
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
to queue.
2007-08-10 10:32:55,250 DEBUG
ManagedExecutableJobResource.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,setInternalState:1690] Setting resource datum internalState to value
WaitingForStateChanges
2007-08-10 10:32:55,251 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-1,setDirty:308] setting dirty flag to true
2007-08-10 10:32:55,251 DEBUG utils.PersistenceHelper [RunQueue
Submit-1,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:55,252 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4 [RunQueue
Submit-1,setResourceDatum:146] Setting resource datum topicListener to value
[Lorg.globus.exec.generated.TopicListenerDescriptionType;@1412c60
2007-08-10 10:32:55,258 DEBUG
ManagedJobResourceImpl.f6232450-4756-11dc-b514-aa329bd042c4
[Thread-29,getResourceDatum:217] getting resource datum localJobId
2007-08-10 10:32:55,259 DEBUG monitoring.JobStateMonitor
[Thread-29,registerJobID:223] Entering registerJobID:
f711ffda-4756-11dc-b4e6-000c297b4f57:12969
2007-08-10 10:32:55,260 DEBUG monitoring.JobStateMonitor
[Thread-29,getCachedEvents:396] Entering getCachedEvents()
2007-08-10 10:32:55,261 DEBUG monitoring.JobStateMonitor
[Thread-29,getCachedEvents:412] Exiting getCachedEvents()
2007-08-10 10:32:55,262 DEBUG exec.PersistentManagedExecutableJobResource
[RunQueue Submit-1,setDirty:308] setting dirty flag to false
2007-08-10 10:32:55,262 DEBUG utils.PersistenceHelper [RunQueue
Submit-1,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:55,263 DEBUG StateMachine.performance [RunQueue
Submit-1,stop:71] [processSubmitState][RunQueue Submit-1][497]
2007-08-10 10:32:55,263 DEBUG exec.RunThread [RunQueue Submit-1,run:104]
processState returned
2007-08-10 10:32:55,263 DEBUG exec.RunThread [RunQueue Submit-1,run:109] Done
processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:55,264 DEBUG monitoring.JobStateMonitor
[Thread-29,registerJobID:239] Exiting registerJobID
2007-08-10 10:32:55,264 DEBUG utils.JobStateMonitorSubscriptionManager
[Thread-29,run:188] Done processing state for
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f6232450-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:55,351 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJob:632] Leaving createSubJob()
2007-08-10 10:32:55,352 DEBUG multi.ManagedMultiJobResource
[Thread-207,createSubJobs:346] Leaving createSubJobs()
2007-08-10 10:32:55,354 DEBUG multi.PersistentManagedMultiJobResource
[Thread-207,run:74] Leaving run()
2007-08-10 10:32:56,682 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,refreshStatus:1698] refreshing state of
job with endpoint Address:
https://192.168.31.172:8443/wsrf/services/ManagedMultiJobService
Reference property[0]:
<ns1:ResourceID
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job">f5a47e70-4756-11dc-b514-aa329bd042c4</ns1:ResourceID>

2007-08-10 10:32:56,777 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,setStubSecurityProperties:1818] setting
factory stub security...using authz method
org.globus.wsrf.impl.security.authorization.HostAuthorization@2c4f5c
2007-08-10 10:32:57,415 DEBUG impl.SubItemHandler [Logical Metadata Thread -
3,writeQueuedItems:232] Entering writeQueuedItems
2007-08-10 10:32:57,416 DEBUG impl.SubItemHandler [Logical Metadata Thread -
3,writeQueuedItems:240] Writting queued items to  itemsToWrite count : 0
2007-08-10 10:32:57,417 DEBUG impl.SubItemHandler [Logical Metadata Thread -
3,writeQueuedItems:262] Copying overflow items to itemsToWrite count : 0
2007-08-10 10:32:57,439 DEBUG impl.SubItemHandler [Logical Metadata Thread -
4,writeQueuedItems:232] Entering writeQueuedItems
2007-08-10 10:32:57,439 DEBUG impl.SubItemHandler [Logical Metadata Thread -
4,writeQueuedItems:240] Writting queued items to  itemsToWrite count : 0
2007-08-10 10:32:57,440 DEBUG impl.SubItemHandler [Logical Metadata Thread -
4,writeQueuedItems:262] Copying overflow items to itemsToWrite count : 0
2007-08-10 10:32:57,451 DEBUG impl.SubItemHandler [Logical Metadata Thread -
2,writeQueuedItems:232] Entering writeQueuedItems
2007-08-10 10:32:57,451 DEBUG impl.SubItemHandler [Logical Metadata Thread -
2,writeQueuedItems:240] Writting queued items to  itemsToWrite count : 0
2007-08-10 10:32:57,453 DEBUG impl.SubItemHandler [Logical Metadata Thread -
2,writeQueuedItems:262] Copying overflow items to itemsToWrite count : 0
2007-08-10 10:32:57,468 DEBUG impl.SubItemHandler [Logical Metadata Thread -
0,writeQueuedItems:232] Entering writeQueuedItems
2007-08-10 10:32:57,471 DEBUG impl.SubItemHandler [Logical Metadata Thread -
0,writeQueuedItems:240] Writting queued items to  itemsToWrite count : 0
2007-08-10 10:32:57,471 DEBUG impl.SubItemHandler [Logical Metadata Thread -
0,writeQueuedItems:262] Copying overflow items to itemsToWrite count : 0
2007-08-10 10:32:57,868 DEBUG impl.SubItemHandler [Logical Metadata Thread -
1,writeQueuedItems:232] Entering writeQueuedItems
2007-08-10 10:32:57,868 DEBUG impl.SubItemHandler [Logical Metadata Thread -
1,writeQueuedItems:240] Writting queued items to  itemsToWrite count : 0
2007-08-10 10:32:57,869 DEBUG impl.SubItemHandler [Logical Metadata Thread -
1,writeQueuedItems:262] Copying overflow items to itemsToWrite count : 0
2007-08-10 10:32:58,090 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,091 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,093 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,093 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,095 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,095 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,096 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,110 INFO  client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,refreshStatus:1734] Raw status query
response message:
<ns1:state
xmlns:ns1="http://www.globus.org/namespaces/2004/10/gram/job/types">Unsubmitted</ns1:state><ns2:holding
xmlns:ns2="http://www.globus.org/namespaces/2004/10/gram/job/types">false</ns2:holding>
2007-08-10 10:32:58,110 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,refreshStatus:1738] Deserializing "state".
2007-08-10 10:32:58,112 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,refreshStatus:1743] Deserializing
"holding".
2007-08-10 10:32:58,112 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,setState:341] setting job state to
Unsubmitted
2007-08-10 10:32:58,112 DEBUG client.GramJob [Rsync transfer
f449d070-4756-11dc-b513-aa329bd042c4,setState:344] holding: false
2007-08-10 10:32:58,145 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,145 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,146 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,172 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,deliver:1202] Entering deliver()
2007-08-10 10:32:58,172 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,deliver:1203] Notification Message Type:
org.globus.exec.generated.StateChangeNotificationMessageWrapperType
2007-08-10 10:32:58,174 DEBUG multi.PersistentManagedMultiJobResource
[ServiceThread-23,processStateNotification:85] Entering
processStateNotification()
2007-08-10 10:32:58,174 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,processStateNotification:1235] Entering
processStateNotification()
2007-08-10 10:32:58,175 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,processStateNotification:1236] Processing State Active
2007-08-10 10:32:58,175 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,getResourceDatum:217] getting resource datum subJobCount
2007-08-10 10:32:58,176 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,getResourceDatum:217] getting resource datum holdingCount
2007-08-10 10:32:58,188 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,processStateNotification:1312] Setting activeCount to 1
2007-08-10 10:32:58,189 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,processStateNotification:1371] Leaving
processStateNotification()
2007-08-10 10:32:58,190 DEBUG utils.PersistenceHelper
[ServiceThread-23,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:58,190 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,setResourceDatum:146] Setting resource datum topicListener to
value [Lorg.globus.exec.generated.TopicListenerDescriptionType;@9ffe4d
2007-08-10 10:32:58,218 DEBUG utils.PersistenceHelper
[ServiceThread-23,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:58,219 DEBUG multi.PersistentManagedMultiJobResource
[ServiceThread-23,processStateNotification:98] Leaving
processStateNotification()
2007-08-10 10:32:58,219 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,deliver:1224] Leaving deliver()
2007-08-10 10:32:58,225 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,227 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,227 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,229 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,229 DEBUG multi.ManagedMultiJobResource
[ServiceThread-22,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,356 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,357 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,357 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,358 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,358 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,368 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,401 DEBUG utils.PersistenceHelper
[ServiceThread-27,store:77] Dirty flag not set: resource will not be stored
2007-08-10 10:32:58,503 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,505 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,506 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,506 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,507 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,getSecurityDescriptor:1386] MJR security descriptor authz:
gridmap
2007-08-10 10:32:58,578 DEBUG utils.PersistenceHelper
[ServiceThread-22,store:77] Dirty flag not set: resource will not be stored
2007-08-10 10:32:59,174 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,deliver:1202] Entering deliver()
2007-08-10 10:32:59,174 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,deliver:1203] Notification Message Type:
org.globus.exec.generated.StateChangeNotificationMessageWrapperType
2007-08-10 10:32:59,175 DEBUG multi.PersistentManagedMultiJobResource
[ServiceThread-27,processStateNotification:85] Entering
processStateNotification()
2007-08-10 10:32:59,175 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,processStateNotification:1235] Entering
processStateNotification()
2007-08-10 10:32:59,176 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,processStateNotification:1236] Processing State CleanUp
2007-08-10 10:32:59,177 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-27,getResourceDatum:217] getting resource datum subJobCount
2007-08-10 10:32:59,177 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-27,getResourceDatum:217] getting resource datum holdingCount
2007-08-10 10:32:59,178 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,processStateNotification:1371] Leaving
processStateNotification()
2007-08-10 10:32:59,179 DEBUG utils.PersistenceHelper
[ServiceThread-27,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:59,180 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-27,setResourceDatum:146] Setting resource datum topicListener to
value [Lorg.globus.exec.generated.TopicListenerDescriptionType;@1d897de
2007-08-10 10:32:59,193 DEBUG utils.PersistenceHelper
[ServiceThread-27,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:59,194 DEBUG multi.PersistentManagedMultiJobResource
[ServiceThread-27,processStateNotification:98] Leaving
processStateNotification()
2007-08-10 10:32:59,195 DEBUG multi.ManagedMultiJobResource
[ServiceThread-27,deliver:1224] Leaving deliver()
2007-08-10 10:32:59,421 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,deliver:1202] Entering deliver()
2007-08-10 10:32:59,422 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,deliver:1203] Notification Message Type:
org.globus.exec.generated.StateChangeNotificationMessageWrapperType
2007-08-10 10:32:59,423 DEBUG multi.PersistentManagedMultiJobResource
[ServiceThread-23,processStateNotification:85] Entering
processStateNotification()
2007-08-10 10:32:59,423 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,processStateNotification:1235] Entering
processStateNotification()
2007-08-10 10:32:59,424 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,processStateNotification:1236] Processing State Done
2007-08-10 10:32:59,425 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,getResourceDatum:217] getting resource datum subJobCount
2007-08-10 10:32:59,425 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,getResourceDatum:217] getting resource datum holdingCount
2007-08-10 10:32:59,426 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,processStateNotification:1348] Setting doneCount to 1
2007-08-10 10:32:59,426 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,processStateNotification:1371] Leaving
processStateNotification()
2007-08-10 10:32:59,427 DEBUG utils.PersistenceHelper
[ServiceThread-23,store:82] storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
with state Unsubmitted
2007-08-10 10:32:59,428 DEBUG
ManagedJobResourceImpl.f5a47e70-4756-11dc-b514-aa329bd042c4
[ServiceThread-23,setResourceDatum:146] Setting resource datum topicListener to
value [Lorg.globus.exec.generated.TopicListenerDescriptionType;@19b0120
2007-08-10 10:32:59,440 DEBUG utils.PersistenceHelper
[ServiceThread-23,store:121] done storing resource
{http://www.globus.org/namespaces/2004/10/gram/job}ResourceID=f5a47e70-4756-11dc-b514-aa329bd042c4
2007-08-10 10:32:59,441 DEBUG multi.PersistentManagedMultiJobResource
[ServiceThread-23,processStateNotification:98] Leaving
processStateNotification()
2007-08-10 10:32:59,441 DEBUG multi.ManagedMultiJobResource
[ServiceThread-23,deliver:1224] Leaving deliver()

------- Comment #10 From Patrick Doran 2007-08-20 13:03:26 -------

Some more diagnostic information:

So far we have only seen this issue when submitting DDM multijobs, and we have
not been able to get GRAM into the unrepsonsive state solely submitting simple
jobs through globusrun-ws. However, once we get GRAM into the unresponsive
state, even simple jobs submitted through globusrun-ws hang as unsubmitted.

We've seen the issue most often when one of the nodes involved in the transfer
was a SuSE VM with somewhat constrained resources, so we believe this may be a
timing issue that is exacerbated by running in a constrained environment.

DDM builds up a multijob description configured to use delegated credentials,
and we use org.globus.exec.client.GramJob to build and submit the job. The
subjobs run on two different nodes with rsync running on one node and a rsh
listener running on the node. I've included the snippet where we check the
submitted status on the multijob below. 

Code checking submitted status:

        // Get our port
        WSResourcePropertiesServiceAddressingLocator jobLocator =
                new WSResourcePropertiesServiceAddressingLocator();
        multiJob = jobLocator.getGetResourcePropertyPort(multiJobEPR);
        DdmSecurityManager.setSecurityOptions(
                (Stub) multiJob, firstTransfer, originalSubject, false);

        // Wait until the job is done submitting
        Thread.sleep(1500);
        StateEnumeration state = this.multiJob.getState();
        int waitcount = 0;
        long timeout = System.currentTimeMillis() +
                       MULTIJOB_SUBMIT_TIMEOUT * 1000;
        while (state == null) {
            Thread.sleep(2000);
            waitcount++;
            this.multiJob.refreshStatus();
            state = this.multiJob.getState();
            // Job not reponding, don't wait forever, treat as failed
            if (System.currentTimeMillis() >= timeout) {
                String msg = LoggingConstants.TRANSIENT_ERROR +
                             " Timed out submitting job to GRAM.";
                TransferDestinationSubmitTimeoutException timeoutEx =
                        new TransferDestinationSubmitTimeoutException(msg);
                transferLog.warn(msg);
                command.setDdmException(timeoutEx);
                throw timeoutEx;
            }
        }

        timeout = System.currentTimeMillis() +
                  RSYNC_JOB_SUBMIT_TIMEOUT * 1000;
        waitcount = 0;
        // Wait until we have submitted the subjob
        // Wait until we have submitted the subjob
        while (state.equals(StateEnumeration.Unsubmitted)) {
            Thread.sleep(2000);
            waitcount++;
            serviceLog.trace("GRAM sub-job status: Unsubmitted.");
            this.multiJob.refreshStatus();
            state = this.multiJob.getState();
            // Job not reponding, don't wait forever, treat as failed
            if (System.currentTimeMillis() >= timeout) {
                String msg = LoggingConstants.TRANSIENT_ERROR +
                             " Timed out submitting rsync sub-job to GRAM.";
                /*TransferDestinationSubmitTimeoutException timeoutEx =
                        new TransferDestinationSubmitTimeoutException(msg);*/
                transferLog.warn(msg);
                //command.setDdmException(timeoutEx);
                //throw timeoutEx;
            }
        }

------- Comment #11 From Patrick Doran 2007-08-20 13:12:27 -------

Martin pointed me to 4984 and 5363 which deal bugs related to caching of IDs
for multijobs. Not sure if this is related to the behavior we are seeing, but
DDM is explicitly assigning the Job ID on the multijob using the following
function:

/**
     * <p>Returns a new ID using a DCE UUID provided by Axis GUIDgen.</p>
     *
     */
    public static synchronized String getNewID() throws Exception {
        int count = 0;
        UUIDGen uuidGen = UUIDGenFactory.getUUIDGen();
        String idRef = uuidGen.nextUUID();
        String idNew = uuidGen.nextUUID();

        // Make sure the LFN is unique
        while (idRef.equals(idNew)) {
            if (count > ID_MAX_TRIES) {
                throw new Exception(
                        "getNewLFN: Unable to generate new LFN.");
            }
            count++;
            idNew = uuidGen.nextUUID();
        }

        return idNew;
    }

------- Comment #12 From Stuart Martin 2009-03-19 09:38:11 -------

Martin has done some work on multi job processing in 4.2.  Could be this is now
resolved there.  Please reopen if it is still a problem.