2008-07-21 17:13:46,101-0500 DEBUG Loader Recompilation suppressed.
2008-07-21 17:13:47,342-0500 INFO  unknown Using sites file: ./sites.xml
2008-07-21 17:13:47,343-0500 INFO  unknown Using tc.data: ./tc.data
2008-07-21 17:13:48,090-0500 WARN  JavaUtils Unable to find required classes (javax.activation.DataHandler and javax.mail.internet.MimeMultipart). Attachment support is disabled.
2008-07-21 17:13:49,132-0500 INFO  unknown Swift svn swift-r2140 cog-r2070

2008-07-21 17:13:49,133-0500 INFO  unknown RUNID id=tag:benc@ci.uchicago.edu,2007:swift:run:20080721-1713-zkz78kcf
2008-07-21 17:13:49,347-0500 INFO  AbstractDataNode closed tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000001
2008-07-21 17:13:49,351-0500 INFO  AbstractDataNode ROOTPATH dataset=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000001 path=$
2008-07-21 17:13:49,351-0500 INFO  AbstractDataNode VALUE dataset=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000001 VALUE=Hello, world!
2008-07-21 17:13:49,378-0500 INFO  New NEW id=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000001
2008-07-21 17:13:49,426-0500 INFO  AbstractDataNode Found mapped data org.griphyn.vdl.mapping.RootDataNode identifier tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002 with no value at dataset=outfile (not closed).$
2008-07-21 17:13:49,426-0500 INFO  New NEW id=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002
2008-07-21 17:13:49,453-0500 INFO  greeting PROCEDURE thread=0 name=greeting
2008-07-21 17:13:49,456-0500 INFO  vdl:parameterlog PARAM thread=0 direction=output variable=t provenanceid=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002
2008-07-21 17:13:49,461-0500 INFO  AbstractDataNode closed tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000003
2008-07-21 17:13:49,462-0500 INFO  AbstractDataNode ROOTPATH dataset=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000003 path=$
2008-07-21 17:13:49,462-0500 INFO  AbstractDataNode VALUE dataset=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000003 VALUE=hello.txt
2008-07-21 17:13:49,470-0500 INFO  vdl:execute START thread=0 tr=echo
2008-07-21 17:13:49,484-0500 INFO  WeightedHostScoreScheduler Sorted: [bgps:0.000(1.000):0/1 overload: 0]
2008-07-21 17:13:49,485-0500 DEBUG WeightedHostScoreScheduler Rand: 0.3951059049265021, sum: 1.0
2008-07-21 17:13:49,485-0500 DEBUG WeightedHostScoreScheduler Next contact: bgps:0.000(1.000):0/1 overload: 0
2008-07-21 17:13:49,488-0500 INFO  vdl:initshareddir START host=bgps - Initializing shared directory
2008-07-21 17:13:49,490-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.000(1.000):1/1 overload: 0, -0.01)
2008-07-21 17:13:49,491-0500 DEBUG WeightedHostScoreScheduler Old score: 0.000, new score: -0.010
2008-07-21 17:13:49,499-0500 INFO  GlobalSubmitQueue No global submit throttle set. Using default (100)
2008-07-21 17:13:49,542-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429428) setting status to Submitting
2008-07-21 17:13:49,543-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429428) setting status to Submitted
2008-07-21 17:13:49,543-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429428) setting status to Active
2008-07-21 17:13:49,544-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429428) setting status to Completed
2008-07-21 17:13:49,545-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.010(0.994):1/1 overload: -41, 0.01)
2008-07-21 17:13:49,545-0500 DEBUG WeightedHostScoreScheduler Old score: -0.010, new score: 0.000
2008-07-21 17:13:49,545-0500 INFO  LateBindingScheduler Task(type=FILE_OPERATION, identity=urn:0-1-1216678429428) Completed. Waiting: 0, Running: 0. Heap size: 36M, Heap free: 2M, Max heap: 511M
2008-07-21 17:13:49,554-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.000(1.000):1/1 overload: 0, -0.2)
2008-07-21 17:13:49,555-0500 DEBUG WeightedHostScoreScheduler Old score: 0.000, new score: -0.200
2008-07-21 17:13:49,564-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429431) setting status to Submitting
2008-07-21 17:13:49,565-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429431) setting status to Submitted
2008-07-21 17:13:49,565-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429431) setting status to Active
2008-07-21 17:13:49,568-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429431) setting status to Completed
2008-07-21 17:13:49,569-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.200(0.889):1/1 overload: -38, 0.2)
2008-07-21 17:13:49,569-0500 DEBUG WeightedHostScoreScheduler Old score: -0.200, new score: 0.000
2008-07-21 17:13:49,569-0500 INFO  LateBindingScheduler Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429431) Completed. Waiting: 0, Running: 0. Heap size: 36M, Heap free: 1M, Max heap: 511M
2008-07-21 17:13:49,570-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.000(1.000):1/1 overload: 0, -0.2)
2008-07-21 17:13:49,571-0500 DEBUG WeightedHostScoreScheduler Old score: 0.000, new score: -0.200
2008-07-21 17:13:49,571-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429434) setting status to Submitting
2008-07-21 17:13:49,571-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429434) setting status to Submitted
2008-07-21 17:13:49,572-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429434) setting status to Active
2008-07-21 17:13:49,573-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429434) setting status to Completed
2008-07-21 17:13:49,574-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.200(0.889):1/1 overload: -33, 0.2)
2008-07-21 17:13:49,574-0500 DEBUG WeightedHostScoreScheduler Old score: -0.200, new score: 0.000
2008-07-21 17:13:49,574-0500 INFO  LateBindingScheduler Task(type=FILE_TRANSFER, identity=urn:0-1-1216678429434) Completed. Waiting: 0, Running: 0. Heap size: 36M, Heap free: 1M, Max heap: 511M
2008-07-21 17:13:49,575-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.000(1.000):1/1 overload: 0, -0.01)
2008-07-21 17:13:49,576-0500 DEBUG WeightedHostScoreScheduler Old score: 0.000, new score: -0.010
2008-07-21 17:13:49,576-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429437) setting status to Submitting
2008-07-21 17:13:49,576-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429437) setting status to Submitted
2008-07-21 17:13:49,576-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429437) setting status to Active
2008-07-21 17:13:49,577-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429437) setting status to Completed
2008-07-21 17:13:49,577-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.010(0.994):1/1 overload: -9, 0.01)
2008-07-21 17:13:49,577-0500 DEBUG WeightedHostScoreScheduler Old score: -0.010, new score: 0.000
2008-07-21 17:13:49,577-0500 INFO  LateBindingScheduler Task(type=FILE_OPERATION, identity=urn:0-1-1216678429437) Completed. Waiting: 0, Running: 0. Heap size: 36M, Heap free: 1M, Max heap: 511M
2008-07-21 17:13:49,579-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.000(1.000):1/1 overload: 0, -0.01)
2008-07-21 17:13:49,579-0500 DEBUG WeightedHostScoreScheduler Old score: 0.000, new score: -0.010
2008-07-21 17:13:49,579-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429439) setting status to Submitting
2008-07-21 17:13:49,579-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429439) setting status to Submitted
2008-07-21 17:13:49,579-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429439) setting status to Active
2008-07-21 17:13:49,580-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429439) setting status to Completed
2008-07-21 17:13:49,580-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.010(0.994):1/1 overload: -6, 0.01)
2008-07-21 17:13:49,580-0500 DEBUG WeightedHostScoreScheduler Old score: -0.010, new score: 0.000
2008-07-21 17:13:49,581-0500 INFO  LateBindingScheduler Task(type=FILE_OPERATION, identity=urn:0-1-1216678429439) Completed. Waiting: 0, Running: 0. Heap size: 36M, Heap free: 1M, Max heap: 511M
2008-07-21 17:13:49,582-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.000(1.000):1/1 overload: 0, -0.01)
2008-07-21 17:13:49,582-0500 DEBUG WeightedHostScoreScheduler Old score: 0.000, new score: -0.010
2008-07-21 17:13:49,582-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429441) setting status to Submitting
2008-07-21 17:13:49,582-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429441) setting status to Submitted
2008-07-21 17:13:49,582-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429441) setting status to Active
2008-07-21 17:13:49,583-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429441) setting status to Completed
2008-07-21 17:13:49,583-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.010(0.994):1/1 overload: -3, 0.01)
2008-07-21 17:13:49,583-0500 DEBUG WeightedHostScoreScheduler Old score: -0.010, new score: 0.000
2008-07-21 17:13:49,584-0500 INFO  LateBindingScheduler Task(type=FILE_OPERATION, identity=urn:0-1-1216678429441) Completed. Waiting: 0, Running: 0. Heap size: 36M, Heap free: 1M, Max heap: 511M
2008-07-21 17:13:49,585-0500 INFO  vdl:initshareddir END host=bgps - Done initializing shared directory
2008-07-21 17:13:49,588-0500 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=echo-8pd46uvi thread=0-1 host=bgps replicationGroup=7pd46uvi
2008-07-21 17:13:49,595-0500 INFO  vdl:createdirset START jobid=echo-8pd46uvi host=bgps - Initializing directory structure
2008-07-21 17:13:49,598-0500 INFO  vdl:createdirs START path= dir=first-20080721-1713-zkz78kcf/shared - Creating directory structure
2008-07-21 17:13:49,598-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.000(1.000):1/1 overload: 0, -0.01)
2008-07-21 17:13:49,598-0500 DEBUG WeightedHostScoreScheduler Old score: 0.000, new score: -0.010
2008-07-21 17:13:49,599-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429443) setting status to Submitting
2008-07-21 17:13:49,599-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429443) setting status to Submitted
2008-07-21 17:13:49,599-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429443) setting status to Active
2008-07-21 17:13:49,599-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429443) setting status to Completed
2008-07-21 17:13:49,600-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.010(0.994):1/1 overload: 0, 0.01)
2008-07-21 17:13:49,600-0500 DEBUG WeightedHostScoreScheduler Old score: -0.010, new score: 0.000
2008-07-21 17:13:49,600-0500 INFO  LateBindingScheduler Task(type=FILE_OPERATION, identity=urn:0-1-1216678429443) Completed. Waiting: 0, Running: 0. Heap size: 36M, Heap free: 1M, Max heap: 511M
2008-07-21 17:13:49,600-0500 INFO  vdl:createdirset END jobid=echo-8pd46uvi - Done initializing directory structure
2008-07-21 17:13:49,601-0500 INFO  vdl:dostagein START jobid=echo-8pd46uvi - Staging in files
2008-07-21 17:13:49,602-0500 INFO  vdl:dostagein END jobid=echo-8pd46uvi - Staging in finished
2008-07-21 17:13:49,603-0500 DEBUG vdl:execute2 JOB_START jobid=echo-8pd46uvi tr=echo arguments=[Hello, world!] tmpdir=first-20080721-1713-zkz78kcf/jobs/8/echo-8pd46uvi host=bgps
2008-07-21 17:13:49,622-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.000(1.000):1/1 overload: 0, -0.2)
2008-07-21 17:13:49,622-0500 DEBUG WeightedHostScoreScheduler Old score: 0.000, new score: -0.200
2008-07-21 17:13:51,316-0500 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429445) setting status to Submitting
2008-07-21 17:13:51,317-0500 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429445) setting status to Submitted
2008-07-21 17:13:51,317-0500 DEBUG WeightedHostScoreScheduler Submission time for Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429445): 0ms. Score delta: 0.002564102564102564
2008-07-21 17:13:51,318-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.200(0.889):1/1 overload: 0, 0.002564102564102564)
2008-07-21 17:13:51,318-0500 DEBUG WeightedHostScoreScheduler Old score: -0.200, new score: -0.197
2008-07-21 17:13:51,319-0500 INFO  JobSubmissionTaskHandler Job submitted
2008-07-21 17:13:51,755-0500 INFO  StatusThread Found task for jobID urn:0-1-1216678429445
2008-07-21 17:13:51,755-0500 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429445) setting status to Active
2008-07-21 17:13:51,756-0500 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429445) setting status to Completed
2008-07-21 17:13:51,757-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.197(0.891):1/1 overload: 0, 0.2)
2008-07-21 17:13:51,757-0500 DEBUG WeightedHostScoreScheduler Old score: -0.197, new score: 0.003
2008-07-21 17:13:51,758-0500 INFO  LateBindingScheduler Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429445) Completed. Waiting: 0, Running: 0. Heap size: 45M, Heap free: 3M, Max heap: 511M
2008-07-21 17:13:51,760-0500 DEBUG vdl:checkjobstatus START jobid=echo-8pd46uvi
2008-07-21 17:13:51,762-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.003(1.002):1/1 overload: 0, -0.01)
2008-07-21 17:13:51,762-0500 DEBUG WeightedHostScoreScheduler Old score: 0.003, new score: -0.007
2008-07-21 17:13:51,763-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429447) setting status to Submitting
2008-07-21 17:13:51,764-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429447) setting status to Submitted
2008-07-21 17:13:51,764-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429447) setting status to Active
2008-07-21 17:13:51,765-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1216678429447) setting status to Completed
2008-07-21 17:13:51,766-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.007(0.996):1/1 overload: 0, 0.01)
2008-07-21 17:13:51,767-0500 DEBUG WeightedHostScoreScheduler Old score: -0.007, new score: 0.003
2008-07-21 17:13:51,767-0500 INFO  LateBindingScheduler Task(type=FILE_OPERATION, identity=urn:0-1-1216678429447) Completed. Waiting: 0, Running: 0. Heap size: 45M, Heap free: 2M, Max heap: 511M
2008-07-21 17:13:51,768-0500 INFO  vdl:checkjobstatus SUCCESS jobid=echo-8pd46uvi - Success file found
2008-07-21 17:13:51,769-0500 DEBUG vdl:execute2 STAGING_OUT jobid=echo-8pd46uvi
2008-07-21 17:13:51,770-0500 INFO  vdl:dostageout START jobid=echo-8pd46uvi - Staging out files
2008-07-21 17:13:51,778-0500 DEBUG vdl:dostageout FILE_STAGE_OUT_START srcname=hello.txt srcdir=first-20080721-1713-zkz78kcf/shared/ srchost=bgps destdir= desthost=localhost provider=file
2008-07-21 17:13:51,779-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429449) setting status to Submitting
2008-07-21 17:13:51,780-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429449) setting status to Submitted
2008-07-21 17:13:51,780-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429449) setting status to Active
2008-07-21 17:13:51,781-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429449) setting status to Completed
2008-07-21 17:13:51,781-0500 INFO  LateBindingScheduler Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429449) Completed. Waiting: 0, Running: 0. Heap size: 45M, Heap free: 2M, Max heap: 511M
2008-07-21 17:13:51,783-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.003(1.002):1/1 overload: 0, -0.2)
2008-07-21 17:13:51,784-0500 DEBUG WeightedHostScoreScheduler Old score: 0.003, new score: -0.197
2008-07-21 17:13:51,785-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1-1216678429452) setting status to Submitting
2008-07-21 17:13:51,785-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1-1216678429452) setting status to Submitted
2008-07-21 17:13:51,786-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1-1216678429452) setting status to Active
2008-07-21 17:13:51,793-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER, identity=urn:0-1-1-1216678429452) setting status to Completed
2008-07-21 17:13:51,794-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:-0.197(0.891):1/1 overload: 0, 0.2)
2008-07-21 17:13:51,794-0500 DEBUG WeightedHostScoreScheduler Old score: -0.197, new score: 0.003
2008-07-21 17:13:51,795-0500 INFO  LateBindingScheduler Task(type=FILE_TRANSFER, identity=urn:0-1-1-1216678429452) Completed. Waiting: 0, Running: 0. Heap size: 45M, Heap free: 2M, Max heap: 511M
2008-07-21 17:13:51,796-0500 DEBUG vdl:dostageout FILE_STAGE_OUT_END srcname=hello.txt srcdir=first-20080721-1713-zkz78kcf/shared/ srchost=bgps destdir= desthost=localhost provider=file
2008-07-21 17:13:51,798-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429455) setting status to Submitting
2008-07-21 17:13:51,799-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429455) setting status to Submitted
2008-07-21 17:13:51,799-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429455) setting status to Active
2008-07-21 17:13:51,802-0500 DEBUG TaskImpl Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429455) setting status to Completed
2008-07-21 17:13:51,803-0500 INFO  LateBindingScheduler Task(type=FILE_OPERATION, identity=urn:0-1-1-1216678429455) Completed. Waiting: 0, Running: 0. Heap size: 45M, Heap free: 2M, Max heap: 511M
2008-07-21 17:13:51,814-0500 INFO  vdl:dostageout END jobid=echo-8pd46uvi - Staging out finished
2008-07-21 17:13:51,819-0500 DEBUG vdl:execute2 JOB_END jobid=echo-8pd46uvi
2008-07-21 17:13:51,820-0500 DEBUG WeightedHostScoreScheduler Releasing contact 2
2008-07-21 17:13:51,823-0500 INFO  vdl:execute END_SUCCESS thread=0 tr=echo
2008-07-21 17:13:51,874-0500 INFO  CloseDataset Closing org.griphyn.vdl.mapping.RootDataNode identifier tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002 with no value at dataset=outfile (not closed)
2008-07-21 17:13:51,874-0500 INFO  AbstractDataNode closed tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002
2008-07-21 17:13:51,874-0500 INFO  AbstractDataNode ROOTPATH dataset=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002 path=$
2008-07-21 17:13:51,875-0500 INFO  AbstractDataNode FILENAME dataset=tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002 filename=file://localhost/hello.txt
2008-07-21 17:13:51,876-0500 INFO  CloseDataset Partially closing org.griphyn.vdl.mapping.RootDataNode identifier tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002 with no value at dataset=outfile (closed) for statement 88000
2008-07-21 17:13:51,876-0500 INFO  CloseDataset var is org.griphyn.vdl.mapping.RootDataNode identifier tag:benc@ci.uchicago.edu,2008:swift:dataset:20080721-1713-yt7en4g5:720000000002 with no value at dataset=outfile (closed)
2008-07-21 17:13:51,876-0500 INFO  CloseDataset var hash is 1790732988
2008-07-21 17:13:51,876-0500 INFO  CloseDataset variable already closed - skipping partial close processing
2008-07-21 17:13:51,900-0500 INFO  vdl:cleanups START cleanups=[[first-20080721-1713-zkz78kcf, bgps]]
2008-07-21 17:13:51,902-0500 INFO  vdl:cleanup START dir=first-20080721-1713-zkz78kcf host=bgps
2008-07-21 17:13:51,906-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:1.103(1.889):0/1 overload: 0, -0.2)
2008-07-21 17:13:51,907-0500 DEBUG WeightedHostScoreScheduler Old score: 1.103, new score: 0.903
2008-07-21 17:13:51,908-0500 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429457) setting status to Submitting
2008-07-21 17:13:51,908-0500 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429457) setting status to Submitted
2008-07-21 17:13:51,908-0500 DEBUG WeightedHostScoreScheduler Submission time for Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429457): 0ms. Score delta: 0.002564102564102564
2008-07-21 17:13:51,909-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.903(1.688):0/1 overload: 0, 0.002564102564102564)
2008-07-21 17:13:51,909-0500 DEBUG WeightedHostScoreScheduler Old score: 0.903, new score: 0.905
2008-07-21 17:13:51,910-0500 INFO  JobSubmissionTaskHandler Job submitted
2008-07-21 17:13:51,910-0500 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429457) setting status to Active
2008-07-21 17:13:51,910-0500 DEBUG TaskImpl Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429457) setting status to Completed
2008-07-21 17:13:51,911-0500 DEBUG WeightedHostScoreScheduler multiplyScore(bgps:0.905(1.691):0/1 overload: 0, 0.2)
2008-07-21 17:13:51,911-0500 DEBUG WeightedHostScoreScheduler Old score: 0.905, new score: 1.105
2008-07-21 17:13:51,911-0500 INFO  LateBindingScheduler Task(type=JOB_SUBMISSION, identity=urn:0-1-1216678429457) Completed. Waiting: 0, Running: 0. Heap size: 45M, Heap free: 1M, Max heap: 511M
2008-07-21 17:13:51,912-0500 INFO  vdl:cleanup END dir=first-20080721-1713-zkz78kcf host=bgps
2008-07-21 17:13:51,915-0500 DEBUG Loader Swift finished with no errors
2008-07-21 17:13:51,918-0500 INFO  ResourcePool Destroying remote service instance... dummy function, this doesn't really do anything...