In this workflow, we were sending a 5-job wf to karajan. No jobs seemed to reach karajan. The workflow seemed to hang, then swift exited after a while (dont know exactly when) Heres what went to swift.out: not much to go on: -- vz$ cat swift.out Swift v0.3-dev r1339 RunID: 20071029-0831-nouanbe8 angle4 started angle4 started angle4 started angle4 started angle4 started error: Notification(int timeout): socket = new ServerSocket(recvPort); Address already in use Warning: Task handler throws exception and also sets status vz$ -- When I filter out the DEBUG messages, and just look at whats left, I get no clue as to what hapened. The APP EXCEPTIONS below seem like they should be ERROR messages, not DEBUG A few asides that I plan to file bugs on if we agree: 1) Need to determine if all the multi-line error messages pertain to the timestamped message that immediuately preceeds them? Are the logs written in a way that ensures this? If so, maybe there is a better convention for tieing these together, oterhwise you need to look for th pattern of a log message (eg ^2007-*) I guess thats OK, as long as its pretty reliable. A simple way is that each non-toplevel message (ie one without a code of INFO DEBUG ETC) starts with a single space. Then there's a reliable pattern to grep for. 2) Other messages need more info, eg DEBUG Job started with no jobid. (marked below) 2007-10-29 08:31:26,666-0600 INFO Loader awf2.swift: source file is new. Recompiling. 2007-10-29 08:31:33,051-0600 INFO Karajan Validation of XML intermediate file was successful 2007-10-29 08:31:42,747-0600 INFO unknown Using sites file: ./sites.xml 2007-10-29 08:31:42,748-0600 INFO unknown Using tc.data: ./tc.data 2007-10-29 08:31:44,005-0600 DEBUG Boot Booting Falkon 2007-10-29 08:31:44,009-0600 DEBUG Boot Booting gt4.0.0 2007-10-29 08:31:50,591-0600 INFO unknown Swift v0.3-dev r1339 Ë2007-10-29 08:31:50,603-0600 INFO unknown RunID: 20071029-0831-nouanbe8 2007-10-29 08:31:50,795-0600 DEBUG FileResourceCache Got request for resource for localhost(file) 2007-10-29 08:31:50,797-0600 DEBUG FileResourceCache Instantiating new resource for localhost(file) 2007-10-29 08:31:51,005-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:31:51,006-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:31:51,234-0600 INFO vdl:execute START thread=0-1 tr=angle4 2007-10-29 08:31:51,234-0600 INFO vdl:execute START thread=0-3 tr=angle4 2007-10-29 08:31:51,285-0600 INFO vdl:initshareddir START host=UC - Initializing shared directory 2007-10-29 08:31:51,309-0600 INFO vdl:execute START thread=0-4 tr=angle4 2007-10-29 08:31:51,322-0600 INFO vdl:execute START thread=0-2 tr=angle4 2007-10-29 08:31:51,323-0600 INFO vdl:execute START thread=0-5 tr=angle4 2007-10-29 08:31:51,432-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:31:51,432-0600 DEBUG FileResourceCache Instantiating new resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:02,450-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298829) setting status to Active 2007-10-29 08:32:02,451-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/shared) 2007-10-29 08:32:02,604-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8) 2007-10-29 08:32:03,173-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC) 2007-10-29 08:32:03,225-0600 DEBUG FileResourceImpl createDirectory(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8) 2007-10-29 08:32:03,242-0600 DEBUG FileResourceImpl createDirectory(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/shared) 2007-10-29 08:32:03,248-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:03,249-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:03,249-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298829) setting status to Completed 2007-10-29 08:32:03,295-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1193668298835) setting status to Submitted 2007-10-29 08:32:03,301-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:03,302-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:03,302-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:03,304-0600 DEBUG DelegatedFileTransferHandler File transfer with resource local->remote 2007-10-29 08:32:03,308-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1193668298835) setting status to Active 2007-10-29 08:32:04,186-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,186-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:04,187-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1193668298835) setting status to Completed 2007-10-29 08:32:04,191-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1193668298839) setting status to Submitted 2007-10-29 08:32:04,192-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:04,192-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:04,192-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,193-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1193668298839) setting status to Active 2007-10-29 08:32:04,193-0600 DEBUG DelegatedFileTransferHandler File transfer with resource local->remote 2007-10-29 08:32:04,806-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,807-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:04,807-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1193668298839) setting status to Completed 2007-10-29 08:32:04,811-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:04,812-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,812-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298842) setting status to Active 2007-10-29 08:32:04,812-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/kickstart) 2007-10-29 08:32:04,818-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8) 2007-10-29 08:32:04,822-0600 DEBUG FileResourceImpl createDirectory(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/kickstart) 2007-10-29 08:32:04,832-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,832-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:04,833-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298842) setting status to Completed 2007-10-29 08:32:04,836-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:04,837-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,837-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298844) setting status to Active 2007-10-29 08:32:04,838-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/status) 2007-10-29 08:32:04,843-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8) 2007-10-29 08:32:04,847-0600 DEBUG FileResourceImpl createDirectory(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/status) 2007-10-29 08:32:04,853-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,853-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:04,854-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298844) setting status to Completed 2007-10-29 08:32:04,857-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:04,858-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,858-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298846) setting status to Active 2007-10-29 08:32:04,858-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/info) 2007-10-29 08:32:04,864-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8) 2007-10-29 08:32:04,868-0600 DEBUG FileResourceImpl createDirectory(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/info) 2007-10-29 08:32:04,930-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,931-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:04,931-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298846) setting status to Completed 2007-10-29 08:32:04,935-0600 INFO vdl:initshareddir END host=UC - Done initializing shared directory 2007-10-29 08:32:04,941-0600 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=angle4-cjxe2cji thread=0-3 host=UC 2007-10-29 08:32:04,942-0600 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=angle4-ejxe2cji thread=0-1 host=UC 2007-10-29 08:32:04,942-0600 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=angle4-djxe2cji thread=0-2 host=UC 2007-10-29 08:32:04,943-0600 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=angle4-gjxe2cji thread=0-5 host=UC 2007-10-29 08:32:04,943-0600 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=angle4-fjxe2cji thread=0-4 host=UC 2007-10-29 08:32:04,986-0600 INFO vdl:createdirset START jobid=angle4-ejxe2cji host=UC - Initializing directory structure 2007-10-29 08:32:04,990-0600 INFO vdl:createdirset START jobid=angle4-gjxe2cji host=UC - Initializing directory structure 2007-10-29 08:32:04,992-0600 INFO vdl:createdirs START path= dir=awf2-20071029-0831-nouanbe8/shared - Creating directory structure Ë2007-10-29 08:32:04,994-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:04,995-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,995-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298848) setting status to Active 2007-10-29 08:32:04,995-0600 DEBUG FileResourceImpl exists(/home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/shared/) 2007-10-29 08:32:04,999-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:04,999-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:05,000-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1193668298848) setting status to Completed 2007-10-29 08:32:05,002-0600 INFO vdl:createdirset END jobid=angle4-gjxe2cji - Done initializing directory structure 2007-10-29 08:32:05,002-0600 INFO vdl:createdirset END jobid=angle4-ejxe2cji - Done initializing directory structure 2007-10-29 08:32:05,004-0600 INFO vdl:dostagein START jobid=angle4-gjxe2cji - Staging in files 2007-10-29 08:32:05,005-0600 INFO vdl:dostagein START jobid=angle4-ejxe2cji - Staging in files 2007-10-29 08:32:05,048-0600 INFO vdl:createdirset START jobid=angle4-fjxe2cji host=UC - Initializing directory structure 2007-10-29 08:32:05,049-0600 INFO vdl:createdirset END jobid=angle4-fjxe2cji - Done initializing directory structure 2007-10-29 08:32:05,051-0600 INFO vdl:dostagein START jobid=angle4-fjxe2cji - Staging in files 2007-10-29 08:32:05,054-0600 INFO vdl:createdirset START jobid=angle4-djxe2cji host=UC - Initializing directory structure 2007-10-29 08:32:05,055-0600 INFO vdl:createdirset END jobid=angle4-djxe2cji - Done initializing directory structure 2007-10-29 08:32:05,080-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:05,107-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,107-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-5-1-1193668298850) setting status to Active 2007-10-29 08:32:05,109-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,110-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:05,110-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-5-1-1193668298850) setting status to Completed 2007-10-29 08:32:05,136-0600 INFO vdl:createdirset START jobid=angle4-cjxe2cji host=UC - Initializing directory structure 2007-10-29 08:32:05,137-0600 INFO vdl:dostagein START jobid=angle4-djxe2cji - Staging in files 2007-10-29 08:32:05,138-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:05,239-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,240-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1193668298853) setting status to Active 2007-10-29 08:32:05,242-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,242-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:05,242-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1193668298853) setting status to Completed 2007-10-29 08:32:05,138-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:05,247-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,247-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-4-1-1193668298856) setting status to Active 2007-10-29 08:32:05,249-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,249-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:05,250-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-4-1-1193668298856) setting status to Completed 2007-10-29 08:32:05,252-0600 INFO vdl:createdirset END jobid=angle4-cjxe2cji - Done initializing directory structure 2007-10-29 08:32:05,267-0600 INFO vdl:dostagein START jobid=angle4-cjxe2cji - Staging in files 2007-10-29 08:32:05,269-0600 DEBUG vdl:dostagein FILE_STAGE_IN_START file=file://localhost/pc2.pcap srchost=localhost srcdir= srcname=pc2.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:05,297-0600 DEBUG vdl:dostagein FILE_STAGE_IN_START file=file://localhost/pc5.pcap srchost=localhost srcdir= srcname=pc5.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:05,298-0600 DEBUG vdl:dostagein FILE_STAGE_IN_START file=file://localhost/pc4.pcap srchost=localhost srcdir= srcname=pc4.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:05,301-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:05,301-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,302-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1-1193668298859) setting status to Active 2007-10-29 08:32:05,304-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,304-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:05,305-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1-1193668298859) setting status to Completed 2007-10-29 08:32:05,336-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-4-1-1193668298865) setting status to Submitted 2007-10-29 08:32:05,340-0600 DEBUG vdl:dostagein FILE_STAGE_IN_START file=file://localhost/pc3.pcap srchost=localhost srcdir= srcname=pc3.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:05,341-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-5-1-1193668298862) setting status to Submitted 2007-10-29 08:32:05,343-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:05,343-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-4-1-1193668298865) setting status to Active 2007-10-29 08:32:05,379-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1-1193668298868) setting status to Submitted 2007-10-29 08:32:05,343-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:05,380-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:05,381-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:05,381-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:05,382-0600 DEBUG FileResourceCache Instantiating new resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:05,382-0600 DEBUG DelegatedFileTransferHandler File transfer with resource local->remote 2007-10-29 08:32:05,405-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1-1193668298868) setting status to Active 2007-10-29 08:32:05,405-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:05,406-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,406-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-3-1-1193668298871) setting status to Active 2007-10-29 08:32:05,408-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:05,408-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:05,409-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-3-1-1193668298871) setting status to Completed 2007-10-29 08:32:05,410-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1-1193668298874) setting status to Submitted 2007-10-29 08:32:05,412-0600 DEBUG vdl:dostagein FILE_STAGE_IN_START file=file://localhost/pc1.pcap srchost=localhost srcdir= srcname=pc1.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:05,414-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:05,414-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:05,415-0600 DEBUG FileResourceCache Instantiating new resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:05,440-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1-1193668298874) setting status to Active 2007-10-29 08:32:05,453-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org Ï2007-10-29 08:32:05,453-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:05,454-0600 DEBUG FileResourceCache Instantiating new resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:05,479-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-5-1-1193668298862) setting status to Active 2007-10-29 08:32:08,584-0600 DEBUG DelegatedFileTransferHandler File transfer with resource local->remote 2007-10-29 08:32:09,280-0600 DEBUG DelegatedFileTransferHandler File transfer with resource local->remote 2007-10-29 08:32:09,757-0600 DEBUG DelegatedFileTransferHandler File transfer with resource local->remote 2007-10-29 08:32:27,579-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@1c0df993) 2007-10-29 08:32:27,580-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@1c0df993) successfully released 2007-10-29 08:32:27,580-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1-1193668298874) setting status to Completed 2007-10-29 08:32:27,604-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-3-1-1193668298878) setting status to Submitted 2007-10-29 08:32:27,607-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:27,608-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:27,609-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@1c0df993) 2007-10-29 08:32:27,610-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-3-1-1193668298878) setting status to Active 2007-10-29 08:32:27,611-0600 DEBUG DelegatedFileTransferHandler File transfer with resource local->remote 2007-10-29 08:32:27,616-0600 DEBUG vdl:dostagein FILE_STAGE_IN_END file=file://localhost/pc3.pcap srchost=localhost srcdir= srcname=pc3.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:27,617-0600 INFO vdl:dostagein END jobid=angle4-djxe2cji - Staging in finished 2007-10-29 08:32:27,619-0600 DEBUG vdl:execute2 JOB_START jobid=angle4-djxe2cji tr=angle4 arguments=[pc3.pcap, of-91d67ce1-d6a4-464e-a099-a7982188fbad-2, cf-1a98b8e0-2477-4a3b-98e7-28d4741c2abe-2] tmpdir=awf2-20071029-0831-nouanbe8/angle4-djxe2cji host=UC 2007-10-29 08:32:27,772-0600 DEBUG JobSubmissionTaskHandler server:http://tg-login1.uc.teragrid.org:50011/wsrf/services/GenericPortal/core/WS/GPFactoryService 2007-10-29 08:32:27,786-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:27,787-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:27,787-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-4-1-1193668298865) setting status to Completed 2007-10-29 08:32:27,789-0600 DEBUG vdl:dostagein FILE_STAGE_IN_END file=file://localhost/pc5.pcap srchost=localhost srcdir= srcname=pc5.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:27,796-0600 INFO vdl:dostagein END jobid=angle4-fjxe2cji - Staging in finished 2007-10-29 08:32:27,798-0600 DEBUG vdl:execute2 JOB_START jobid=angle4-fjxe2cji tr=angle4 arguments=[pc5.pcap, of-91d67ce1-d6a4-464e-a099-a7982188fbad-4, cf-1a98b8e0-2477-4a3b-98e7-28d4741c2abe-4] tmpdir=awf2-20071029-0831-nouanbe8/angle4-fjxe2cji host=UC 2007-10-29 08:32:27,807-0600 DEBUG ResourcePool Notification initialized on port: 50101 2007-10-29 08:32:27,809-0600 DEBUG ResourcePool WORKER: Machine ID = tg-login1.uc.teragrid.org:50101 2007-10-29 08:32:27,813-0600 DEBUG SubmissionThread Falkon:userID: 192.5.198.197 2007-10-29 08:32:27,949-0600 DEBUG JobSubmissionTaskHandler server:http://tg-login1.uc.teragrid.org:50011/wsrf/services/GenericPortal/core/WS/GPFactoryService 2007-10-29 08:32:28,387-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@4e533994) 2007-10-29 08:32:28,387-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@4e533994) successfully released 2007-10-29 08:32:28,387-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1-1193668298868) setting status to Completed 2007-10-29 08:32:28,389-0600 DEBUG vdl:dostagein FILE_STAGE_IN_END file=file://localhost/pc4.pcap srchost=localhost srcdir= srcname=pc4.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:28,390-0600 INFO vdl:dostagein END jobid=angle4-ejxe2cji - Staging in finished 2007-10-29 08:32:28,391-0600 DEBUG vdl:execute2 JOB_START jobid=angle4-ejxe2cji tr=angle4 arguments=[pc4.pcap, of-91d67ce1-d6a4-464e-a099-a7982188fbad-3, cf-1a98b8e0-2477-4a3b-98e7-28d4741c2abe-3] tmpdir=awf2-20071029-0831-nouanbe8/angle4-ejxe2cji host=UC 2007-10-29 08:32:28,406-0600 DEBUG JobSubmissionTaskHandler server:http://tg-login1.uc.teragrid.org:50011/wsrf/services/GenericPortal/core/WS/GPFactoryService 2007-10-29 08:32:30,553-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@1bcd3993) 2007-10-29 08:32:30,569-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@1bcd3993) successfully released 2007-10-29 08:32:30,570-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-5-1-1193668298862) setting status to Completed 2007-10-29 08:32:30,571-0600 DEBUG vdl:dostagein FILE_STAGE_IN_END file=file://localhost/pc2.pcap srchost=localhost srcdir= srcname=pc2.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:30,572-0600 INFO vdl:dostagein END jobid=angle4-gjxe2cji - Staging in finished 2007-10-29 08:32:30,573-0600 DEBUG vdl:execute2 JOB_START jobid=angle4-gjxe2cji tr=angle4 arguments=[pc2.pcap, of-91d67ce1-d6a4-464e-a099-a7982188fbad-1, cf-1a98b8e0-2477-4a3b-98e7-28d4741c2abe-1] tmpdir=awf2-20071029-0831-nouanbe8/angle4-gjxe2cji host=UC 2007-10-29 08:32:30,587-0600 DEBUG JobSubmissionTaskHandler server:http://tg-login1.uc.teragrid.org:50011/wsrf/services/GenericPortal/core/WS/GPFactoryService 2007-10-29 08:32:33,415-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-2-1193668298883) setting status to Failed 2007-10-29 08:32:33,590-0600 DEBUG JobSubmissionTaskHandler directory: /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8 2007-10-29 08:32:33,590-0600 DEBUG JobSubmissionTaskHandler directory: /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8 2007-10-29 08:32:33,591-0600 DEBUG JobSubmissionTaskHandler directory: /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8 2007-10-29 08:32:33,594-0600 DEBUG JobSubmissionTaskHandler executable: /bin/sh 2007-10-29 08:32:33,594-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-5-1193668298889) setting status to Submitted MW problems start here 2007-10-29 08:32:33,595-0600 INFO JobSubmissionTaskHandler Job submitted MW ^^^ message should have job ID 2007-10-29 08:32:33,596-0600 DEBUG vdl:execute2 APPLICATION_EXCEPTION jobid=angle4-djxe2cji - Application exception: Task failed task:execute @ vdl-int.k, line: 362 sys:sequential @ vdl-int.k, line: 355 sys:try @ vdl-int.k, line: 354 task:allocatehost @ vdl-int.k, line: 336 vdl:execute2 @ execute-default.k, line: 23 sys:restartonerror @ execute-default.k, line: 21 sys:sequential @ execute-default.k, line: 19 sys:try @ execute-default.k, line: 18 sys:if @ execute-default.k, line: 17 sys:then @ execute-default.k, line: 16 sys:if @ execute-default.k, line: 15 vdl:execute @ awf2.kml, line: 24 angle4 @ awf2.kml, line: 78 Ï sys:parallelfor @ awf2.kml, line: 59 vdl:mainp @ awf2.kml, line: 58 mainp @ vdl.k, line: 148 vdl:mains @ awf2.kml, line: 57 vdl:mains @ awf2.kml, line: 57 rlog:restartlog @ awf2.kml, line: 55 kernel:project @ awf2.kml, line: 2 awf2-20071029-0831-nouanbe8 MW ^^ Is this message the first and main indication of failure? Is it for the actual job submission? What was the actual failure? Is it non-zero return code from the app or from kickstart? 2007-10-29 08:32:33,598-0600 DEBUG JobSubmissionTaskHandler executable: /bin/sh 2007-10-29 08:32:33,598-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-4-1193668298885) setting status to Submitted 2007-10-29 08:32:33,599-0600 INFO JobSubmissionTaskHandler Job submitted 2007-10-29 08:32:33,619-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298891) setting status to Submitted â2007-10-29 08:32:33,619-0600 WARN NonBlockingSubmit Warning: Task handler throws exception and also sets status 2007-10-29 08:32:33,593-0600 DEBUG JobSubmissionTaskHandler executable: /bin/sh 2007-10-29 08:32:33,624-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1193668298887) setting status to Submitted 2007-10-29 08:32:33,780-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:33,800-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298891) setting status to Active 2007-10-29 08:32:33,926-0600 INFO JobSubmissionTaskHandler Job submitted 2007-10-29 08:32:33,927-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:33,927-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:34,005-0600 DEBUG DelegatedFileTransferHandler File transfer with resource remote->tmp 2007-10-29 08:32:34,198-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@1c0df993) 2007-10-29 08:32:34,220-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@1c0df993) successfully released 2007-10-29 08:32:34,221-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-3-1-1193668298878) setting status to Completed 2007-10-29 08:32:34,223-0600 DEBUG vdl:dostagein FILE_STAGE_IN_END file=file://localhost/pc1.pcap srchost=localhost srcdir= srcname=pc1.pcap desthost=UC destdir=awf2-20071029-0831-nouanbe8/shared/ provider=file 2007-10-29 08:32:34,224-0600 INFO vdl:dostagein END jobid=angle4-cjxe2cji - Staging in finished 2007-10-29 08:32:34,225-0600 DEBUG vdl:execute2 JOB_START jobid=angle4-cjxe2cji tr=angle4 arguments=[pc1.pcap, of-91d67ce1-d6a4-464e-a099-a7982188fbad-0, cf-1a98b8e0-2477-4a3b-98e7-28d4741c2abe-0] tmpdir=awf2-20071029-0831-nouanbe8/angle4-cjxe2cji host=UC 2007-10-29 08:32:34,239-0600 DEBUG JobSubmissionTaskHandler server:http://tg-login1.uc.teragrid.org:50011/wsrf/services/GenericPortal/core/WS/GPFactoryService 2007-10-29 08:32:34,240-0600 DEBUG JobSubmissionTaskHandler directory: /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8 2007-10-29 08:32:34,240-0600 DEBUG JobSubmissionTaskHandler executable: /bin/sh 2007-10-29 08:32:34,240-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-3-1193668298894) setting status to Submitted 2007-10-29 08:32:34,241-0600 INFO JobSubmissionTaskHandler Job submitted 2007-10-29 08:32:34,252-0600 DEBUG DelegatedFileTransferHandler Exception in transfer org.globus.cog.abstraction.impl.file.FileResourceException: Exception in getFile at org.globus.cog.abstraction.impl.file.ftp.AbstractFTPFileResource.translateException(AbstractFTPFileResource.java:47) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:341) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.doSource(DelegatedFileTransferHandler.java:276) at org.globus.cog.abstraction.impl.fileTransfer.CachingDelegatedFileTransferHandler.doSource(CachingDelegatedFileTransferHandler.java:60) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:491) at java.lang.Thread.run(Thread.java:568) Caused by: org.globus.ftp.exception.ServerException: Server refused performing the request. Custom message: (error code 1) [Nested exception message: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/angle4-djxe2cji/stderr.txt 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] [Nested exception is org.globus.ftp.exception.UnexpectedReplyCodeException: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/angle4-djxe2cji/stderr.txt 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:101) at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:110) at org.globus.ftp.vanilla.TransferMonitor.run(TransferMonitor.java:195) at org.globus.ftp.vanilla.TransferMonitor.start(TransferMonitor.java:109) at org.globus.ftp.FTPClient.transferRunSingleThread(FTPClient.java:1456) at org.globus.ftp.FTPClient.get(FTPClient.java:1225) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:338) ... 4 more 2007-10-29 08:32:34,256-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:34,256-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:34,257-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298891) setting status to Failed Exception in getFile 2007-10-29 08:32:34,260-0600 DEBUG DelegatedFileTransferHandler File transfer failed org.globus.cog.abstraction.impl.file.FileResourceException: Exception in getFile at org.globus.cog.abstraction.impl.file.ftp.AbstractFTPFileResource.translateException(AbstractFTPFileResource.java:47) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:341) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.doSource(DelegatedFileTransferHandler.java:276) at org.globus.cog.abstraction.impl.fileTransfer.CachingDelegatedFileTransferHandler.doSource(CachingDelegatedFileTransferHandler.java:60) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:491) at java.lang.Thread.run(Thread.java:568) Caused by: org.globus.ftp.exception.ServerException: Server refused performing the request. Custom message: (error code 1) [Nested exception message: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/angle4-djxe2cji/stderr.txt 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] [Nested exception is org.globus.ftp.exception.UnexpectedReplyCodeException: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. Ï500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/angle4-djxe2cji/stderr.txt 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:101) at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:110) at org.globus.ftp.vanilla.TransferMonitor.run(TransferMonitor.java:195) at org.globus.ftp.vanilla.TransferMonitor.start(TransferMonitor.java:109) at org.globus.ftp.FTPClient.transferRunSingleThread(FTPClient.java:1456) at org.globus.ftp.FTPClient.get(FTPClient.java:1225) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:338) ... 4 more 2007-10-29 08:32:34,263-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:34,263-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:34,263-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1193668298896) setting status to Active 2007-10-29 08:32:34,275-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:34,275-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:34,275-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1193668298896) setting status to Completed 2007-10-29 08:32:34,279-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298899) setting status to Submitted 2007-10-29 08:32:34,280-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:34,280-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:34,281-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:34,286-0600 DEBUG DelegatedFileTransferHandler File transfer with resource remote->tmp 2007-10-29 08:32:34,303-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298899) setting status to Active 2007-10-29 08:32:34,505-0600 DEBUG DelegatedFileTransferHandler Exception in transfer org.globus.cog.abstraction.impl.file.FileResourceException: Exception in getFile at org.globus.cog.abstraction.impl.file.ftp.AbstractFTPFileResource.translateException(AbstractFTPFileResource.java:47) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:341) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.doSource(DelegatedFileTransferHandler.java:276) at org.globus.cog.abstraction.impl.fileTransfer.CachingDelegatedFileTransferHandler.doSource(CachingDelegatedFileTransferHandler.java:60) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:491) at java.lang.Thread.run(Thread.java:568) Caused by: org.globus.ftp.exception.ServerException: Server refused performing the request. Custom message: (error code 1) [Nested exception message: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/angle4-djxe2cji/stdout.txt 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] [Nested exception is org.globus.ftp.exception.UnexpectedReplyCodeException: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/angle4-djxe2cji/stdout.txt 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:101) at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:110) at org.globus.ftp.vanilla.TransferMonitor.run(TransferMonitor.java:195) at org.globus.ftp.vanilla.TransferMonitor.start(TransferMonitor.java:109) at org.globus.ftp.FTPClient.transferRunSingleThread(FTPClient.java:1456) at org.globus.ftp.FTPClient.get(FTPClient.java:1225) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:338) ... 4 more 2007-10-29 08:32:34,507-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:34,507-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:34,507-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298899) setting status to Failed Exception in getFile 2007-10-29 08:32:34,511-0600 DEBUG DelegatedFileTransferHandler File transfer failed org.globus.cog.abstraction.impl.file.FileResourceException: Exception in getFile at org.globus.cog.abstraction.impl.file.ftp.AbstractFTPFileResource.translateException(AbstractFTPFileResource.java:47) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:341) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.doSource(DelegatedFileTransferHandler.java:276) at org.globus.cog.abstraction.impl.fileTransfer.CachingDelegatedFileTransferHandler.doSource(CachingDelegatedFileTransferHandler.java:60) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:491) at java.lang.Thread.run(Thread.java:568) Caused by: org.globus.ftp.exception.ServerException: Server refused performing the request. Custom message: (error code 1) [Nested exception message: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/angle4-djxe2cji/stdout.txt 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] [Nested exception is org.globus.ftp.exception.UnexpectedReplyCodeException: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/angle4-djxe2cji/stdout.txt 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:101) at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:110) at org.globus.ftp.vanilla.TransferMonitor.run(TransferMonitor.java:195) at org.globus.ftp.vanilla.TransferMonitor.start(TransferMonitor.java:109) at org.globus.ftp.FTPClient.transferRunSingleThread(FTPClient.java:1456) at org.globus.ftp.FTPClient.get(FTPClient.java:1225) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:338) ... 4 more 2007-10-29 08:32:34,511-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:34,512-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:34,513-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1193668298902) setting status to Active 2007-10-29 08:32:34,515-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) Ï2007-10-29 08:32:34,581-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:34,581-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1193668298902) setting status to Completed 2007-10-29 08:32:34,590-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298905) setting status to Submitted 2007-10-29 08:32:34,591-0600 DEBUG DelegatedFileTransferHandler Starting service on gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:32:34,592-0600 DEBUG FileResourceCache Got request for resource for gsiftp://tg-gridftp.uc.teragrid.org(gsiftp) 2007-10-29 08:32:34,592-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:34,594-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298905) setting status to Active 2007-10-29 08:32:34,598-0600 DEBUG DelegatedFileTransferHandler File transfer with resource remote->tmp 2007-10-29 08:32:34,808-0600 DEBUG DelegatedFileTransferHandler Exception in transfer org.globus.cog.abstraction.impl.file.FileResourceException: Exception in getFile at org.globus.cog.abstraction.impl.file.ftp.AbstractFTPFileResource.translateException(AbstractFTPFileResource.java:47) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:341) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.doSource(DelegatedFileTransferHandler.java:276) at org.globus.cog.abstraction.impl.fileTransfer.CachingDelegatedFileTransferHandler.doSource(CachingDelegatedFileTransferHandler.java:60) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:491) at java.lang.Thread.run(Thread.java:568) Caused by: org.globus.ftp.exception.ServerException: Server refused performing the request. Custom message: (error code 1) [Nested exception message: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/kickstart/angle4-djxe2cji-kickstart.xml 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] [Nested exception is org.globus.ftp.exception.UnexpectedReplyCodeException: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/kickstart/angle4-djxe2cji-kickstart.xml 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:101) at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:110) at org.globus.ftp.vanilla.TransferMonitor.run(TransferMonitor.java:195) at org.globus.ftp.vanilla.TransferMonitor.start(TransferMonitor.java:109) at org.globus.ftp.FTPClient.transferRunSingleThread(FTPClient.java:1456) at org.globus.ftp.FTPClient.get(FTPClient.java:1225) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:338) ... 4 more 2007-10-29 08:32:34,809-0600 DEBUG FileResourceCache Releasing resource for gsiftp://tg-gridftp.uc.teragrid.org (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) 2007-10-29 08:32:34,809-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.gridftp.FileResourceImpl@5fb97997) successfully released 2007-10-29 08:32:34,810-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-2-1193668298905) setting status to Failed Exception in getFile 2007-10-29 08:32:34,813-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:34,813-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:34,814-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1193668298908) setting status to Active 2007-10-29 08:32:34,814-0600 DEBUG DelegatedFileTransferHandler File transfer failed org.globus.cog.abstraction.impl.file.FileResourceException: Exception in getFile at org.globus.cog.abstraction.impl.file.ftp.AbstractFTPFileResource.translateException(AbstractFTPFileResource.java:47) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:341) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.doSource(DelegatedFileTransferHandler.java:276) at org.globus.cog.abstraction.impl.fileTransfer.CachingDelegatedFileTransferHandler.doSource(CachingDelegatedFileTransferHandler.java:60) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:491) at java.lang.Thread.run(Thread.java:568) Caused by: org.globus.ftp.exception.ServerException: Server refused performing the request. Custom message: (error code 1) [Nested exception message: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/kickstart/angle4-djxe2cji-kickstart.xml 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] [Nested exception is org.globus.ftp.exception.UnexpectedReplyCodeException: Custom message: Unexpected reply: 500-Command failed. : globus_l_gfs_file_open failed. 500-globus_xio: Unable to open file /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8/kickstart/angle4-djxe2cji-kickstart.xml 500-globus_xio: System error in open: No such file or directory 500-globus_xio: A system call failed: No such file or directory 500 End.] at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:101) at org.globus.ftp.exception.ServerException.embedUnexpectedReplyCodeException(ServerException.java:110) at org.globus.ftp.vanilla.TransferMonitor.run(TransferMonitor.java:195) at org.globus.ftp.vanilla.TransferMonitor.start(TransferMonitor.java:109) at org.globus.ftp.FTPClient.transferRunSingleThread(FTPClient.java:1456) at org.globus.ftp.FTPClient.get(FTPClient.java:1225) at org.globus.cog.abstraction.impl.file.gridftp.old.FileResourceImpl.getFile(FileResourceImpl.java:338) ... 4 more 2007-10-29 08:32:34,817-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:34,817-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:34,817-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1193668298908) setting status to Completed 2007-10-29 08:32:34,857-0600 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=angle4-hjxe2cji thread=0-2 host=UC 2007-10-29 08:32:34,864-0600 INFO vdl:createdirset START jobid=angle4-hjxe2cji host=UC - Initializing directory structure 2007-10-29 08:32:34,866-0600 INFO vdl:createdirset END jobid=angle4-hjxe2cji - Done initializing directory structure 2007-10-29 08:32:34,867-0600 INFO vdl:dostagein START jobid=angle4-hjxe2cji - Staging in files 2007-10-29 08:32:34,870-0600 DEBUG FileResourceCache Got request for resource for localhost(local) 2007-10-29 08:32:34,870-0600 DEBUG FileResourceCache Found cached resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:34,870-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1-1193668298912) setting status to Active 2007-10-29 08:32:34,871-0600 DEBUG FileResourceCache Releasing resource for localhost (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) 2007-10-29 08:32:34,872-0600 DEBUG FileResourceCache Resource (org.globus.cog.abstraction.impl.file.local.FileResourceImpl@3bcb398a) successfully released 2007-10-29 08:32:34,872-0600 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-2-1-1193668298912) setting status to Completed 2007-10-29 08:32:34,874-0600 INFO vdl:dostagein END jobid=angle4-hjxe2cji - Staging in finished 2007-10-29 08:32:34,875-0600 DEBUG vdl:execute2 JOB_START jobid=angle4-hjxe2cji tr=angle4 arguments=[pc3.pcap, of-91d67ce1-d6a4-464e-a099-a7982188fÏbad-2, cf-1a98b8e0-2477-4a3b-98e7-28d4741c2abe-2] tmpdir=awf2-20071029-0831-nouanbe8/angle4-hjxe2cji host=UC 2007-10-29 08:32:34,884-0600 DEBUG JobSubmissionTaskHandler server:http://tg-login1.uc.teragrid.org:50011/wsrf/services/GenericPortal/core/WS/GPFactoryService 2007-10-29 08:32:34,884-0600 DEBUG JobSubmissionTaskHandler directory: /home/wilde/swift/tmp/UC/awf2-20071029-0831-nouanbe8 2007-10-29 08:32:34,885-0600 DEBUG JobSubmissionTaskHandler executable: /bin/sh 2007-10-29 08:32:34,885-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-2-1193668298915) setting status to Submitted 2007-10-29 08:32:34,885-0600 INFO JobSubmissionTaskHandler Job submitted 2007-10-29 08:34:50,805-0600 DEBUG FileResourceCache Maximum idle time exceeded. Removing resource for gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:34:50,839-0600 DEBUG FileResourceCache Maximum idle time exceeded. Removing resource for gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:34:50,840-0600 DEBUG FileResourceCache Maximum idle time exceeded. Removing resource for gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:34:50,840-0600 DEBUG FileResourceCache Maximum idle time exceeded. Removing resource for gsiftp://tg-gridftp.uc.teragrid.org 2007-10-29 08:34:50,840-0600 DEBUG FileResourceCache Maximum idle time exceeded. Removing resource for localhost