[Swift-devel] Slow job processing by SGE execution provider?

Michael Wilde wilde at mcs.anl.gov
Sat Jan 29 13:35:04 CST 2011


Mihael,

Im running some simple Swift tests on the "siraf" SGE cluster in UC Radiology.

The swift script runs 10 cat jobs with one tiny input file (and in this case, no output files, even though an output dataset was mapped).

I see the following unexpected behavior:

The siraf cluster schedules jobs very quickly. The 10 jobs are launched and finished (as seen by a "watch qstat" command) in the first few seconds of the script's execution.

But then, swift slowly logs the completions on stdout at a rate of less than one per second, so the overall workflow takes almost 40 seconds when it should finish in say 5-10 seconds. The same behavior occurs when I send in 50 or 100 jobs - the jobs get through SGE *very* quickly, and then swift sluggishly recognizes their completion.

Its almost like SGE qstat is polled less than once per second, and only one completed job is recognized per poll. 

Also note that the progress log on stdout makes it look like Swift thinks only one job is active at a time, when in fact all 10 of the jobs have long finished as seen by an external qstat.

The stdout and a sample log is below.

You can see from the stdout that the completions were recognized piecemeal rather than in large batches at once.  The same workflow finishes very rapidly both on siraf running on the local exec provider and on PADS under PBS.


--- stdout and log:

sir$ time swift -tc.file tc -sites.file sge.xml -config cf catsin.swift -n=10
Swift svn swift-r4044 cog-r3044 (cog modified locally)

RunID: 20110129-1337-00pltm8f
Progress:
Progress:  Submitting:8  Submitted:2
Progress:  Submitted:10
Progress:  Submitted:9  Active:1
Progress:  Submitted:8  Active:1  Finished successfully:1
Progress:  Submitted:7  Active:1  Finished successfully:2
Progress:  Submitted:6  Active:1  Finished successfully:3
Progress:  Submitted:5  Active:1  Finished successfully:4
Progress:  Submitted:4  Active:1  Finished successfully:5
Progress:  Submitted:3  Active:1  Finished successfully:6
Progress:  Submitted:2  Active:1  Finished successfully:7
Progress:  Submitted:1  Active:1  Finished successfully:8
Progress:  Active:1  Finished successfully:9
Final status:  Finished successfully:10

real	0m38.315s
user	0m4.890s
sys	0m0.583s
sir$ ls -lt *.log | head -3
-rw-r--r-- 1 mwilde ml-giger  22865 Jan 29 13:38 catsin-20110129-1337-00pltm8f.log
-rw-r--r-- 1 mwilde ml-giger   1653 Jan 29 13:37 swift.log
-rw-r--r-- 1 mwilde ml-giger  30749 Jan 29 10:28 catsin-20110129-1027-019p3p32.log
sir$ cat *8f.log
2011-01-29 13:37:35,128-0600 DEBUG Loader Max heap: 238616576
2011-01-29 13:37:35,128-0600 DEBUG Loader kmlversion is >a13cb327-aa83-47c5-9340-53e068ae5e33<
2011-01-29 13:37:35,128-0600 DEBUG Loader build version is >a13cb327-aa83-47c5-9340-53e068ae5e33<
2011-01-29 13:37:35,129-0600 DEBUG Loader Recompilation suppressed.
2011-01-29 13:37:35,340-0600 INFO  VDL2ExecutionContext Stack dump:
Level 1
[iA = 0, iB = 0, bA = false, bB = false]
	vdl:instanceconfigfile = cf
	vdl:instanceconfig = Swift configuration [cf]
	vdl:operation = run
	PATH_SEPARATOR = /
	swift.home = /home/mwilde/swift/rev/trunk/bin/..


2011-01-29 13:37:36,047-0600 INFO  unknown Using sites file: sge.xml
2011-01-29 13:37:36,094-0600 INFO  unknown Using tc.data: tc
2011-01-29 13:37:36,235-0600 INFO  AbstractScheduler Setting resources to: {sge=sge}
2011-01-29 13:37:36,879-0600 INFO  unknown Swift svn swift-r4044 cog-r3044 (cog modified locally)

2011-01-29 13:37:36,879-0600 INFO  unknown RUNID id=run:20110129-1337-00pltm8f
2011-01-29 13:37:36,967-0600 INFO  SetFieldValue Set: swift#mapper#17000=outdir
2011-01-29 13:37:36,967-0600 INFO  SetFieldValue Set: swift#mapper#17004=.out
2011-01-29 13:37:36,967-0600 INFO  SetFieldValue Set: swift#mapper#17002=f.
2011-01-29 13:37:36,967-0600 INFO  VDLFunction FUNCTION: arg()
2011-01-29 13:37:36,968-0600 INFO  VDLFunction FUNCTION: toint()
2011-01-29 13:37:36,979-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000028 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,979-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000032 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,979-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000031 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,979-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000029 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,979-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000030 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,980-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000035 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,980-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000033 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,980-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000034 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,980-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000036 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,980-0600 INFO  AbstractDataNode Found data org.griphyn.vdl.mapping.RootDataNode identifier dataset:20110129-1337-qcgf98ff:720000000028 type file with no value at dataset=data (closed).$
2011-01-29 13:37:36,989-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,990-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,991-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,991-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,992-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,993-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,989-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,990-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,990-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,990-0600 INFO  VDLFunction FUNCTION: filename()
2011-01-29 13:37:36,996-0600 INFO  vdl:execute START thread=0-3-5-1 tr=cat
2011-01-29 13:37:36,996-0600 INFO  vdl:execute START thread=0-3-8-1 tr=cat
2011-01-29 13:37:36,996-0600 INFO  vdl:execute START thread=0-3-10-1 tr=cat
2011-01-29 13:37:36,996-0600 INFO  vdl:execute START thread=0-3-6-1 tr=cat
2011-01-29 13:37:36,997-0600 INFO  vdl:execute START thread=0-3-4-1 tr=cat
2011-01-29 13:37:36,997-0600 INFO  vdl:execute START thread=0-3-3-1 tr=cat
2011-01-29 13:37:36,997-0600 INFO  vdl:execute START thread=0-3-7-1 tr=cat
2011-01-29 13:37:36,997-0600 INFO  vdl:execute START thread=0-3-9-1 tr=cat
2011-01-29 13:37:36,998-0600 INFO  vdl:execute START thread=0-3-1-1 tr=cat
2011-01-29 13:37:37,000-0600 INFO  vdl:execute START thread=0-3-2-1 tr=cat
2011-01-29 13:37:37,015-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,015-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,015-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,016-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,016-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,016-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,016-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,016-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,017-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,017-0600 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=sge, score=99.854
2011-01-29 13:37:37,019-0600 INFO  GlobalSubmitQueue No global submit throttle set. Using default (1024)
2011-01-29 13:37:37,020-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,024-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,027-0600 INFO  vdl:initshareddir START host=sge - Initializing shared directory
2011-01-29 13:37:37,135-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,154-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,158-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,161-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,166-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,167-0600 INFO  vdl:initshareddir END host=sge - Done initializing shared directory
2011-01-29 13:37:37,180-0600 INFO  vdl:createdirset START jobid=cat-8gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,180-0600 INFO  vdl:createdirset START jobid=cat-4gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,181-0600 INFO  vdl:createdirset START jobid=cat-agnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,180-0600 INFO  vdl:createdirset START jobid=cat-7gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,180-0600 INFO  vdl:createdirset START jobid=cat-5gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,181-0600 INFO  vdl:createdirset START jobid=cat-6gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-8gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,181-0600 INFO  vdl:createdirset START jobid=cat-9gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,181-0600 INFO  vdl:createdirset START jobid=cat-2gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,181-0600 INFO  vdl:createdirset START jobid=cat-3gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-6gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-9gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-2gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,183-0600 INFO  vdl:dostagein START jobid=cat-8gnyo65k - Staging in files
2011-01-29 13:37:37,183-0600 INFO  vdl:dostagein START jobid=cat-9gnyo65k - Staging in files
2011-01-29 13:37:37,183-0600 INFO  vdl:dostagein START jobid=cat-2gnyo65k - Staging in files
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-5gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset START jobid=cat-1gnyo65k host=sge - Initializing directory structure
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-4gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-7gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-agnyo65k - Done initializing directory structure
2011-01-29 13:37:37,183-0600 INFO  vdl:dostagein START jobid=cat-6gnyo65k - Staging in files
2011-01-29 13:37:37,185-0600 INFO  vdl:dostagein START jobid=cat-5gnyo65k - Staging in files
2011-01-29 13:37:37,185-0600 INFO  vdl:dostagein START jobid=cat-4gnyo65k - Staging in files
2011-01-29 13:37:37,182-0600 INFO  vdl:createdirset END jobid=cat-3gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,185-0600 INFO  vdl:dostagein START jobid=cat-7gnyo65k - Staging in files
2011-01-29 13:37:37,185-0600 INFO  vdl:createdirset END jobid=cat-1gnyo65k - Done initializing directory structure
2011-01-29 13:37:37,185-0600 INFO  vdl:dostagein START jobid=cat-agnyo65k - Staging in files
2011-01-29 13:37:37,186-0600 INFO  vdl:dostagein START jobid=cat-3gnyo65k - Staging in files
2011-01-29 13:37:37,187-0600 INFO  vdl:dostagein START jobid=cat-1gnyo65k - Staging in files
2011-01-29 13:37:37,194-0600 INFO  LateBindingScheduler JobQueue: 2
2011-01-29 13:37:37,194-0600 INFO  LateBindingScheduler JobQueue: 2
2011-01-29 13:37:37,195-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,196-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,196-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,197-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,197-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,198-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,198-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,198-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,212-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-agnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-2gnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-4gnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-7gnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-3gnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-8gnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-6gnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-5gnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-9gnyo65k - Staging in finished
2011-01-29 13:37:37,214-0600 INFO  vdl:dostagein END jobid=cat-1gnyo65k - Staging in finished
2011-01-29 13:37:37,239-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-agnyo65k -jobdir a -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,240-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-7gnyo65k -jobdir 7 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,240-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-3gnyo65k -jobdir 3 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,239-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-2gnyo65k -jobdir 2 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,239-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-1gnyo65k -jobdir 1 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,240-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-6-1-1-1296329856121) is /bin/bash shared/_swiftwrap cat-1gnyo65k -jobdir 1 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,241-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-6gnyo65k -jobdir 6 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,241-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-3-1-1-1296329856126) is /bin/bash shared/_swiftwrap cat-6gnyo65k -jobdir 6 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,239-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-8gnyo65k -jobdir 8 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,242-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-5-1-1-1296329856124) is /bin/bash shared/_swiftwrap cat-8gnyo65k -jobdir 8 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,242-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-4gnyo65k -jobdir 4 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,242-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-9-1-1-1296329856128) is /bin/bash shared/_swiftwrap cat-4gnyo65k -jobdir 4 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,239-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-5gnyo65k -jobdir 5 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,239-0600 INFO  Execute Submit: in: catsin-20110129-1337-00pltm8f command: /bin/bash shared/_swiftwrap cat-9gnyo65k -jobdir 9 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,243-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-10-1-1-1296329856122) is /bin/bash shared/_swiftwrap cat-9gnyo65k -jobdir 9 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,243-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-7-1-1-1296329856123) is /bin/bash shared/_swiftwrap cat-5gnyo65k -jobdir 5 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,240-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-2-1-1-1296329856118) is /bin/bash shared/_swiftwrap cat-2gnyo65k -jobdir 2 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,240-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-1-1-1-1296329856117) is /bin/bash shared/_swiftwrap cat-3gnyo65k -jobdir 3 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,240-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-4-1-1-1296329856120) is /bin/bash shared/_swiftwrap cat-agnyo65k -jobdir a -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,240-0600 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-8-1-1-1296329856119) is /bin/bash shared/_swiftwrap cat-7gnyo65k -jobdir 7 -scratch  -e /bin/cat -out stdout.txt -err stderr.txt -i -d  -if data.txt -of  -k  -cdmfile  -status provider -a data.txt
2011-01-29 13:37:37,941-0600 INFO  SGEExecutor Job id from qsub: 712380
2011-01-29 13:37:38,069-0600 INFO  SGEExecutor Job id from qsub: 712381
2011-01-29 13:37:38,188-0600 INFO  SGEExecutor Job id from qsub: 712382
2011-01-29 13:37:38,195-0600 INFO  AbstractQueuePoller Actively monitored: 0, New: 3, Done: 0
2011-01-29 13:37:38,223-0600 INFO  SGEExecutor Job id from qsub: 712383
2011-01-29 13:37:38,388-0600 INFO  SGEExecutor Job id from qsub: 712384
2011-01-29 13:37:38,397-0600 INFO  SGEExecutor Job id from qsub: 712385
2011-01-29 13:37:38,574-0600 INFO  SGEExecutor Job id from qsub: 712386
2011-01-29 13:37:38,911-0600 INFO  SGEExecutor Job id from qsub: 712387
2011-01-29 13:37:38,917-0600 INFO  SGEExecutor Job id from qsub: 712388
2011-01-29 13:37:39,220-0600 INFO  SGEExecutor Job id from qsub: 712389
2011-01-29 13:37:50,037-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:50,048-0600 INFO  vdl:dostageout START jobid=cat-agnyo65k - Staging out files
2011-01-29 13:37:50,053-0600 INFO  vdl:dostageout END jobid=cat-agnyo65k - Staging out finished
2011-01-29 13:37:50,250-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:50,254-0600 INFO  vdl:execute END_SUCCESS thread=0-3-4-1 tr=cat
2011-01-29 13:37:51,272-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:51,276-0600 INFO  vdl:dostageout START jobid=cat-3gnyo65k - Staging out files
2011-01-29 13:37:51,277-0600 INFO  vdl:dostageout END jobid=cat-3gnyo65k - Staging out finished
2011-01-29 13:37:51,396-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:51,401-0600 INFO  vdl:execute END_SUCCESS thread=0-3-1-1 tr=cat
2011-01-29 13:37:52,634-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:52,634-0600 INFO  AbstractQueuePoller Actively monitored: 3, New: 7, Done: 3
2011-01-29 13:37:52,636-0600 INFO  vdl:dostageout START jobid=cat-7gnyo65k - Staging out files
2011-01-29 13:37:52,637-0600 INFO  vdl:dostageout END jobid=cat-7gnyo65k - Staging out finished
2011-01-29 13:37:52,788-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:37:52,790-0600 INFO  vdl:execute END_SUCCESS thread=0-3-8-1 tr=cat
2011-01-29 13:38:03,788-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:03,791-0600 INFO  vdl:dostageout START jobid=cat-2gnyo65k - Staging out files
2011-01-29 13:38:03,792-0600 INFO  vdl:dostageout END jobid=cat-2gnyo65k - Staging out finished
2011-01-29 13:38:03,931-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:03,934-0600 INFO  vdl:execute END_SUCCESS thread=0-3-2-1 tr=cat
2011-01-29 13:38:05,274-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:05,275-0600 INFO  vdl:dostageout START jobid=cat-1gnyo65k - Staging out files
2011-01-29 13:38:05,276-0600 INFO  vdl:dostageout END jobid=cat-1gnyo65k - Staging out finished
2011-01-29 13:38:05,375-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:05,377-0600 INFO  vdl:execute END_SUCCESS thread=0-3-6-1 tr=cat
2011-01-29 13:38:06,790-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:06,792-0600 INFO  vdl:dostageout START jobid=cat-9gnyo65k - Staging out files
2011-01-29 13:38:06,792-0600 INFO  vdl:dostageout END jobid=cat-9gnyo65k - Staging out finished
2011-01-29 13:38:06,955-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:06,957-0600 INFO  vdl:execute END_SUCCESS thread=0-3-10-1 tr=cat
2011-01-29 13:38:08,248-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:08,249-0600 INFO  vdl:dostageout START jobid=cat-4gnyo65k - Staging out files
2011-01-29 13:38:08,250-0600 INFO  vdl:dostageout END jobid=cat-4gnyo65k - Staging out finished
2011-01-29 13:38:08,324-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:08,326-0600 INFO  vdl:execute END_SUCCESS thread=0-3-9-1 tr=cat
2011-01-29 13:38:09,482-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:09,483-0600 INFO  vdl:dostageout START jobid=cat-5gnyo65k - Staging out files
2011-01-29 13:38:09,484-0600 INFO  vdl:dostageout END jobid=cat-5gnyo65k - Staging out finished
2011-01-29 13:38:10,380-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:10,381-0600 INFO  vdl:execute END_SUCCESS thread=0-3-7-1 tr=cat
2011-01-29 13:38:10,906-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:10,907-0600 INFO  vdl:dostageout START jobid=cat-6gnyo65k - Staging out files
2011-01-29 13:38:10,907-0600 INFO  vdl:dostageout END jobid=cat-6gnyo65k - Staging out finished
2011-01-29 13:38:11,362-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:11,363-0600 INFO  vdl:execute END_SUCCESS thread=0-3-3-1 tr=cat
2011-01-29 13:38:12,732-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:12,732-0600 INFO  AbstractQueuePoller Actively monitored: 7, New: 0, Done: 7
2011-01-29 13:38:12,733-0600 INFO  vdl:dostageout START jobid=cat-8gnyo65k - Staging out files
2011-01-29 13:38:12,734-0600 INFO  vdl:dostageout END jobid=cat-8gnyo65k - Staging out finished
2011-01-29 13:38:12,982-0600 INFO  LateBindingScheduler JobQueue: 0
2011-01-29 13:38:12,984-0600 INFO  vdl:execute END_SUCCESS thread=0-3-5-1 tr=cat
2011-01-29 13:38:12,996-0600 INFO  vdl:cleanups START cleanups=[[catsin-20110129-1337-00pltm8f, sge]]
2011-01-29 13:38:12,997-0600 INFO  vdl:cleanup START dir=catsin-20110129-1337-00pltm8f host=sge
2011-01-29 13:38:12,999-0600 INFO  vdl:cleanup END dir=catsin-20110129-1337-00pltm8f host=sge
2011-01-29 13:38:12,999-0600 INFO  vdl:cleanups END cleanups=[[catsin-20110129-1337-00pltm8f, sge]]
2011-01-29 13:38:13,002-0600 INFO  Loader Swift finished with no errors
sir$ 

--- script, sites and properties files:

sir$ more catsin.swift sge.xml cf
::::::::::::::
catsin.swift
::::::::::::::
type file;

app  cat (file i)
{
  cat @i ;
}

file out[]<simple_mapper; location="outdir", prefix="f.",suffix=".out">;
foreach j in [1:@toint(@arg("n","1"))] {
  file data<"data.txt">;
    cat(data);
}
::::::::::::::
sge.xml
::::::::::::::
<config>
  <pool handle="sge">
    <profile namespace="globus" key="maxwalltime">00:01:00</profile>
    <execution provider="sge" url="none" />
    <profile namespace="globus" key="pe">shm</profile>
    <profile namespace="karajan" key="initialScore">10000</profile>
    <profile namespace="karajan" key="jobThrottle">.10</profile>
    <filesystem provider="local" />
    <workdirectory >/home/mwilde/swiftwork</workdirectory>
  </pool>
</config>
::::::::::::::
cf
::::::::::::::
wrapperlog.always.transfer=true
sitedir.keep=true
execution.retries=0
lazy.errors=false
status.mode=provider
use.provider.staging=false
provider.staging.pin.swiftfiles=false
sir$ 


-- 
Michael Wilde
Computation Institute, University of Chicago
Mathematics and Computer Science Division
Argonne National Laboratory




More information about the Swift-devel mailing list