[Swift-devel] Re: can't run ssh:pbs coaster again
Wenjun Wu
wwj at ci.uchicago.edu
Thu Mar 11 14:20:44 CST 2010
Hi Mike,
I posted tc.data, sites.xml and coasters.log here.
Wenjun
coasterpads LoopModel
/autonfs/gpfs-pads/oops/scienceportal/oops-svn/protlib2/bin/LoopModel.sh
null null GLOBUS::maxwalltime="02:00:00"
localhost PrepLoop
/autonfs/gpfs-pads/oops/scienceportal/oops-svn/protlib2/bin/preploop.sh
null null null
localhost PostProcessLoops
/autonfs/gpfs-pads/oops/scienceportal/oops-svn/protlib2/bin/PostProcessLoops.sh
null null null
<pool handle="coasterpads">
<execution provider="coaster" url="login.pads.ci.uchicago.edu"
jobmanager="ssh:pbs"/>
<profile namespace="globus" key="workersPerNode">2</profile>
<profile namespace="globus" key="slots">1</profile>
<profile namespace="globus" key="nodeGranularity">1</profile>
<profile namespace="globus" key="maxNodes">10</profile>
<profile namespace="karajan" key="jobThrottle">0.5</profile>
<profile namespace="karajan" key="initialScore">10000</profile>
<filesystem provider="ssh" url="login.pads.ci.uchicago.edu"/>
<workdirectory>/gpfs/pads/oops/workflows</workdirectory>
</pool>
2010-03-11 11:02:50,617 1195158935 Processing file list
2010-03-11 11:02:50,646 1195158935 Updating jars
2010-03-11 11:02:50,869 1195158935 Forking service
2010-03-11 11:02:50,869 1195158935 Moved coaster jar to head of classpath
2010-03-11 11:02:50,870 1195158935 Args: [nice, -n, 2,
/home/wwj/Desktop/jdk1.5.0_07/bin/java, -Xmx256M,
-DGLOBUS_HOSTNAME=login.pads.ci.uchicago.edu,
-Djava.security.egd=file:///dev/urandom, -cp,
/home/wwj/.globus/coasters/cache/cog-provider-coaster-0.3-ad4cd4f04d7ce5e14eb3cb2fe39b9d60.jar:/home/wwj/.globus/coasters/cache/backport-util
> Wenjun, its possible that your sites.xml is specifying parameters that are not grantable by the cluster. Eg, a queue that doesnt exist, more nodes than exist, more time than is valid for a queue, etc.
>
> Please post your sites.xml and tc files - thats the first place to look for these problems.
>
> The cause may be visible in logs from PBS under $HOME/.globus/{coasters,...}
>
> - Mike
>
> ----- "Wenjun Wu" <wwj at ci.uchicago.edu> wrote:
>
>
>> Hi Mike,
>> I encountered a problem with running coaster on pad again.
>> From the attached log file, the error message says:
>> "Caused by: Could not submit job
>> Caused by:
>> org.globus.cog.abstraction.impl.common.task.TaskSubmissionException:
>> Could not submit job
>> Caused by:
>> org.globus.cog.abstraction.impl.common.task.TaskSubmissionException:
>> Could not start coaster service
>> Caused by:
>> org.globus.cog.abstraction.impl.common.task.TaskSubmissionException:
>> Task ended before registration was received. "
>>
>> Is there any way to figure what might cause this?
>> Thanks,
>>
>> Wenjun
>>
>>> Hi Mike,
>>> Right now I can run the loop model using ssh:pbs through coaster.
>>>
>> But
>>
>>> it can only run one job on one node at one moment.
>>> Whenever I increase the values for workersPerNode, maxNodes and
>>> jobThrottle so that the workflow can run on multiple nodes through
>>> coaster,
>>> it run into a problem. Please take a look at the error message.
>>>
>>> Thanks,
>>>
>>> Wenjun
>>>
>>> Begin PBS Epilogue Mon Mar 1 15:51:56 CST 2010
>>> Job ID: 5754.svc.pads.ci.uchicago.edu
>>> Username: wwj
>>> Group: ci-users
>>> Job Name: null
>>> Session: 32252
>>> Limits: nodes=5,walltime=04:00:00
>>> Resources: cput=00:00:00,mem=708kb,vmem=8400kb,walltime=00:00:02
>>> Nodes:
>>>
>>>
>> c48.pads.ci.uchicago.edu,c46.pads.ci.uchicago.edu,c45.pads.ci.uchicago.edu,c06.pads.ci.uchicago.edu,c07.pads.ci.uchicago.edu
>>
>>
>>> End PBS Epilogue Mon Mar 1 15:51:56 CST 2010
>>> ----------------------------------------
>>>
>>>
>>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.events.FailureNotificationEvent.<init>(FailureNotificationEvent.java:36)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.events.FailureNotificationEvent.<init>(FailureNotificationEvent.java:42)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.nodes.FlowNode.failImmediately(FlowNode.java:147)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.nodes.grid.GridExec.taskFailed(GridExec.java:320)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.nodes.grid.AbstractGridNode.statusChanged(AbstractGridNode.java:276)
>>
>>
>>> at
>>>
>> org.griphyn.vdl.karajan.lib.Execute.statusChanged(Execute.java:104)
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.scheduler.AbstractScheduler.fireJobStatusChangeEvent(AbstractScheduler.java:168)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.scheduler.LateBindingScheduler.statusChanged(LateBindingScheduler.java:661)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.scheduler.WeightedHostScoreScheduler.statusChanged(WeightedHostScoreScheduler.java:424)
>>
>>
>>> at
>>>
>>>
>> org.griphyn.vdl.karajan.VDSAdaptiveScheduler.statusChanged(VDSAdaptiveScheduler.java:410)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.abstraction.impl.common.task.TaskImpl.notifyListeners(TaskImpl.java:236)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.abstraction.impl.common.task.TaskImpl.setStatus(TaskImpl.java:224)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.abstraction.impl.execution.coaster.NotificationManager.setStatus(NotificationManager.java:112)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.abstraction.impl.execution.coaster.NotificationManager.notificationReceived(NotificationManager.java:78)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.abstraction.coaster.service.local.JobStatusHandler.requestComplete(JobStatusHandler.java:45)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.service.handlers.RequestHandler.receiveCompleted(RequestHandler.java:84)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.service.channels.AbstractKarajanChannel.handleRequest(AbstractKarajanChannel.java:348)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel.step(AbstractStreamKarajanChannel.java:156)
>>
>>
>>> at
>>>
>>>
>> org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Multiplexer.run(AbstractStreamKarajanChannel.java:365)
>>
>>
>>> 2010-03-01 15:52:00,639-0600 INFO ExecutionContext Detailed
>>>
>> exception:
>>
>>> Exception in LoopModel:
>>> Arguments: [output/data//T0510D1.pdb, output/run/T0510D1.14.pdb]
>>> Host: coasterpads
>>> Directory:
>>>
>> psim.loops-20100301-1551-7qejrfd0/jobs/8/LoopModel-89hxehoj
>>
>>> stderr.txt:
>>>
>>> stdout.txt:
>>>
>>> ----
>>>
>>> Caused by: Task failed: 0301-510351-000000 Block task ended
>>>
>> prematurely
>>
>>>> Wenjun, I'll be at Argonne in about an hour - lets try to debug
>>>>
>> this
>>
>>>> together.
>>>>
>>>> Lets do it step by step: first lets test that we can submit ssh
>>>>
>> jobs
>>
>>>> from communicado to pads; then do coasters on top of that
>>>> (provider=ssh:pbs) unless you suggest differently, Mihael.
>>>>
>>>> (The other possibility is ssh from communicado to run *swift* on
>>>> pads. Given that the share /home and /gpfs/pads, this might be a
>>>>
>> good
>>
>>>> easy option?)
>>>>
>>>> - Mike
>>>>
>>>> ----- "Wenjun Wu" <wwj at ci.uchicago.edu> wrote:
>>>>
>>>>
>>>>
>>>>> Hi Mihael,
>>>>> Please find the attached log file and sites.xml.
>>>>> I run the swift script from sidgrid to pads. And ssh "which
>>>>>
>> qsub"
>>
>>>>> returns the right path.
>>>>> But the coaster didn't work for me.
>>>>>
>>>>> Thanks!
>>>>>
>>>>> Wenjun
>>>>>
>>>>>
>>>>>> I think what's happening in Wenjun's case is that qsub is not in
>>>>>>
>>>>>>
>>>>> the
>>>>>
>>>>>
>>>>>> path. I suppose this could be tested by running a simple ssh job
>>>>>>
>>>>>>
>>>>> that
>>>>>
>>>>>
>>>>>> does "which qsub".
>>>>>>
>>>>>> On Thu, 2010-02-25 at 16:08 -0600, Michael Wilde wrote:
>>>>>>
>>>>>>
>>>>>>> Was: Re: [PADS Support #3457] globus services for accessing
>>>>>>>
>> PADS
>>
>>>>>>> --
>>>>>>>
>>>>>>> Hi Wenjun,
>>>>>>>
>>>>>>> Are you doing this from communicado? If so, you need to use ssh
>>>>>>>
>> to
>>
>>>>>>>
>>>>>>>
>>>>> get
>>>>>
>>>>>
>>>>>>> from communicado to PADS. And since when you get there you want
>>>>>>>
>> to
>>
>>>>>>>
>>>>>>>
>>>>> run
>>>>>
>>>>>
>>>>>>> coasters. you need I think to use the coaster provider and
>>>>>>>
>>>>>>>
>>>>> jobmanager
>>>>>
>>>>>
>>>>>>> = ssh:pbs.
>>>>>>>
>>>>>>> I'm cc'ing swift-user and Mihael to discuss the exact sites
>>>>>>>
>>>>>>>
>>>>> options
>>>>>
>>>>>
>>>>>>> needed.
>>>>>>>
>>>>>>> We'd want coasters to use ssh to launch one PBS job to launch
>>>>>>>
>> all
>>
>>>>>>>
>>>>>>>
>>>>> the
>>>>>
>>>>>
>>>>>>> workers.
>>>>>>> I think there are still some issues on PADS with interpreting
>>>>>>>
>>>>>>>
>>>>> #nodes
>>>>>
>>>>>
>>>>>>> and workerspernode correctly, so please bear with us while we
>>>>>>>
>>>>>>>
>>>>> figure
>>>>>
>>>>>
>>>>>>> this out.
>>>>>>>
>>>>>>> I'll try this myself later tonight, but if you discover
>>>>>>>
>> anything
>>
>>>>>>> (either working of failing) please post to the User list.
>>>>>>>
>>>>>>> Thanks,
>>>>>>>
>>>>>>> Mike
>>>>>>>
>>>>>>>
>>>>>>> ----- "Wenjun Wu" <wwj at ci.uchicago.edu> wrote:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>> Hi Mike,
>>>>>>>> I tried to run loop model through ssh+pbs on PADS. The ssh
>>>>>>>>
>>>>>>>>
>>>>> provider
>>>>>
>>>>>
>>>>>>>> seems working but pbs not.
>>>>>>>> Please check the site file and error message in the below:
>>>>>>>>
>>>>>>>> Wenjun
>>>>>>>>
>>>>>>>>
>>>>>>>>> Wenjun,
>>>>>>>>>
>>>>>>>>> I think having GRAM (GRAM5 especially) on PADS would be
>>>>>>>>>
>> useful.
>>
>>>>>>>>> But in the meantime, I think you can also use swift's ssh
>>>>>>>>>
>>>>>>>>>
>>>>> provider
>>>>>
>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>> to get to PADS.
>>>>>>>>
>>>>>>>>
>>>>>>>>> We'll need to try that.
>>>>>>>>>
>>>>>>>>> - Mike
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>> <pool handle="pads">
>>>>>>>> <!-- gridftp url="gsiftp://stor.ci.uchicago.edu"/ -->
>>>>>>>> <filesystem url="login.pads.ci.uchicago.edu"
>>>>>>>>
>> provider="ssh"
>>
>>>>>>>>
>>>>>>>>
>>>>> />
>>>>>
>>>>>
>>>>>>>> <execution provider="pbs" url="svc.pads.ci.uchicago.edu"
>>>>>>>>
>> />
>>
>>>>>>>> <workdirectory>/gpfs/pads/oops/workflows</workdirectory>
>>>>>>>> <profile namespace="karajan"
>>>>>>>>
>> key="jobThrottle">0.03</profile>
>>
>>>>>>>> <profile namespace="karajan"
>>>>>>>>
>>>>>>>>
>>>>> key="initialScore">10000</profile>
>>>>>
>>>>>
>>>>>>>> </pool>
>>>>>>>>
>>>>>>>> Caused by: qstat failed (exit code 255)
>>>>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.karajan.workflow.events.FailureNotificationEvent.<init>(FailureNotificationEvent.java:36)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.karajan.workflow.events.FailureNotificationEvent.<init>(FailureNotificationEvent.java:42)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.karajan.workflow.nodes.FlowNode.failImmediately(FlowNode.java:147)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.karajan.workflow.nodes.grid.GridExec.taskFailed(GridExec.java:320)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.karajan.workflow.nodes.grid.AbstractGridNode.statusChanged(AbstractGridNode.java:276)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.griphyn.vdl.karajan.lib.Execute.statusChanged(Execute.java:104)
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.karajan.scheduler.AbstractScheduler.fireJobStatusChangeEvent(AbstractScheduler.java:168)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.karajan.scheduler.LateBindingScheduler.statusChanged(LateBindingScheduler.java:661)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.karajan.scheduler.WeightedHostScoreScheduler.statusChanged(WeightedHostScoreScheduler.java:424)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.griphyn.vdl.karajan.VDSAdaptiveScheduler.statusChanged(VDSAdaptiveScheduler.java:410)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.common.task.TaskImpl.notifyListeners(TaskImpl.java:236)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.common.task.TaskImpl.setStatus(TaskImpl.java:224)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.common.AbstractDelegatedTaskHandler.failTask(AbstractDelegatedTaskHandler.java:54)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.scheduler.common.AbstractJobSubmissionTaskHandler.processFailed(AbstractJobSubmissionTaskHandler.java:101)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.scheduler.common.AbstractExecutor.processFailed(AbstractExecutor.java:246)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.scheduler.common.Job.fail(Job.java:198)
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.scheduler.common.AbstractQueuePoller.failAll(AbstractQueuePoller.java:141)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.scheduler.common.AbstractQueuePoller.pollQueue(AbstractQueuePoller.java:172)
>>
>>
>>>>>
>>>>>
>>>>>>>> at
>>>>>>>>
>>>>>>>>
>> org.globus.cog.abstraction.impl.scheduler.common.AbstractQueuePoller.run(AbstractQueuePoller.java:80)
>>
>>
>>>>>
>>>>>
>>>>>>>> ... 1 more
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>> ----- "Ti Leggett" <pads-support at ci.uchicago.edu> wrote:
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>> There are currently no Globus job managers, but GridFTP is
>>>>>>>>>>
>> at
>>
>>>>>>>>>> stor.ci.uchicago.edu.
>>>>>>>>>>
>>>>>>>>>> I'll work on getting GRAM up. Do you need WSRF or Pre-WS
>>>>>>>>>>
>> GRAM?
>>
>>>>>>>>>> On Wed Feb 24 14:45:57 2010, wwj at ci.uchicago.edu wrote:
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>> Hello,
>>>>>>>>>>> Could you please tell me whether there is any globus
>>>>>>>>>>>
>>>>>>>>>>>
>>>>> services
>>>>>
>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>> for
>>>>>>>>
>>>>>>>>
>>>>>>>>>>> PADS such as GridFTP and GRAM?
>>>>>>>>>>> I'm trying to launch jobs to PADS remotely but can't
>>>>>>>>>>>
>> figure
>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>> out
>>>>>>>>
>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>> what
>>>>>>>>>>
>>>>>>>>>>> are the right URLs for the GridFTP
>>>>>>>>>>> service and GRAM.
>>>>>>>>>>> Thanks!
>>>>>>>>>>>
>>>>>>>>>>> Wenjun
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>
>>>>>>
>>>>> 2010-02-25 17:12:00,157-0600 DEBUG Loader Max heap: 266403840
>>>>> 2010-02-25 17:12:00,159-0600 DEBUG Loader kmlversion is
>>>>>
>>>>>
>>>>>> cd1f7f6b-6e05-4723-ac70-e8683b56ae98<
>>>>>>
>>>>>>
>>>>> 2010-02-25 17:12:00,159-0600 DEBUG Loader build version is
>>>>>
>>>>>
>>>>>> f3073b05-a317-4f56-a26f-f87b6abd1af3<
>>>>>>
>>>>>>
>>>>> 2010-02-25 17:12:00,159-0600 INFO Loader psim.loops.swift:
>>>>>
>> source
>>
>>>>> file was compiled with a different version of Swift. Recompiling.
>>>>> 2010-02-25 17:12:01,274-0600 INFO Karajan Validation of XML
>>>>> intermediate file was successful
>>>>> 2010-02-25 17:12:01,982-0600 INFO VDL2ExecutionContext Stack
>>>>>
>> dump:
>>
>>>>> Level 1
>>>>> [iA = 0, iB = 0, bA = false, bB = false]
>>>>> vdl:instanceconfig = Swift configuration []
>>>>> vdl:operation = run
>>>>> swift.home =
>>>>> /home/wwj/SIDGrid/swift/cog-branch/modules/swift/dist/swift-svn
>>>>> PATH_SEPARATOR = /
>>>>>
>>>>>
>>>>> 2010-02-25 17:12:02,907-0600 INFO unknown Using sites file:
>>>>> ./sites.xml
>>>>> 2010-02-25 17:12:02,908-0600 INFO unknown Using tc.data:
>>>>>
>> ./tc.data
>>
>>>>> 2010-02-25 17:12:03,089-0600 INFO AbstractScheduler Setting
>>>>>
>> resources
>>
>>>>> to: {pads=pads, localhost=localhost, pbs=pbs,
>>>>> pbs-coaster=pbs-coaster}
>>>>> 2010-02-25 17:12:03,711-0600 INFO unknown Swift svn swift-r3246
>>>>> cog-r2721
>>>>>
>>>>> 2010-02-25 17:12:03,713-0600 INFO unknown RUNID
>>>>> id=tag:benc at ci.uchicago.edu,2007:swift:run:20100225-1712-3zrtb5i5
>>>>> 2010-02-25 17:12:03,916-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000001
>>
>>
>>>>> type string value=input dataset=unnamed SwiftScript value
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:03,925-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000001
>>
>>
>>>>> 2010-02-25 17:12:03,925-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000002
>>
>>
>>>>> type string value=LoopModelResults.map dataset=unnamed
>>>>>
>> SwiftScript
>>
>>>>> value (closed)
>>>>> 2010-02-25 17:12:03,925-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000002
>>
>>
>>>>> 2010-02-25 17:12:03,925-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000003
>>
>>
>>>>> type string value=indir dataset=unnamed SwiftScript value
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:03,926-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000003
>>
>>
>>>>> 2010-02-25 17:12:03,926-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000004
>>
>>
>>>>> type string value=output dataset=unnamed SwiftScript value
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:03,926-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000004
>>
>>
>>>>> 2010-02-25 17:12:03,926-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000005
>>
>>
>>>>> type string value=outdir dataset=unnamed SwiftScript value
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:03,926-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000005
>>
>>
>>>>> 2010-02-25 17:12:03,926-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000006
>>
>>
>>>>> type string value=protein dataset=unnamed SwiftScript value
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:03,927-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000006
>>
>>
>>>>> 2010-02-25 17:12:03,927-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000007
>>
>>
>>>>> type string value=LoopModelData.map dataset=unnamed SwiftScript
>>>>>
>> value
>>
>>>>> (closed)
>>>>> 2010-02-25 17:12:03,927-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000007
>>
>>
>>>>> 2010-02-25 17:12:03,927-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000008
>>
>>
>>>>> type string value=4 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:03,927-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000008
>>
>>
>>>>> 2010-02-25 17:12:03,928-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000009
>>
>>
>>>>> type string value=LoopModelOutArray.map dataset=unnamed
>>>>>
>> SwiftScript
>>
>>>>> value (closed)
>>>>> 2010-02-25 17:12:03,928-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000009
>>
>>
>>>>> 2010-02-25 17:12:03,928-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000010
>>
>>
>>>>> type string value=LoopModelIn.map dataset=unnamed SwiftScript
>>>>>
>> value
>>
>>>>> (closed)
>>>>> 2010-02-25 17:12:03,928-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000010
>>
>>
>>>>> 2010-02-25 17:12:03,928-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000011
>>
>>
>>>>> type string value=nSim dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:03,928-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000011
>>
>>
>>>>> 2010-02-25 17:12:03,932-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000012
>>
>>
>>>>> type int value=1.0 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:03,932-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000012
>>
>>
>>>>> 2010-02-25 17:12:03,933-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000013
>>
>>
>>>>> type int value=0.0 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:03,933-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000013
>>
>>
>>>>> 2010-02-25 17:12:03,946-0600 INFO modelloops STARTCOMPOUND
>>>>>
>> thread=0-1
>>
>>>>> name=ModelLoops
>>>>> 2010-02-25 17:12:03,973-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000014
>>
>>
>>>>> 2010-02-25 17:12:03,976-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000015
>>
>>
>>>>> 2010-02-25 17:12:03,978-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000016
>>
>>
>>>>> 2010-02-25 17:12:03,979-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000017
>>
>>
>>>>> 2010-02-25 17:12:03,985-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000018
>>
>>
>>>>> 2010-02-25 17:12:03,987-0600 INFO AbstractDataNode Adding handle
>>>>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000019
>>
>>
>>>>> type LoopModelIn with no value at dataset=modelIn (not closed)"
>>>>>
>> to
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000018
>>
>>
>>>>> type string with no value at dataset=swift#mapper#17007 (not
>>>>>
>> closed)"
>>
>>>>> 2010-02-25 17:12:03,987-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000019
>>
>>
>>>>> 2010-02-25 17:12:03,989-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000020
>>
>>
>>>>> 2010-02-25 17:12:03,991-0600 INFO AbstractDataNode Adding handle
>>>>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>>
>> closed)" to
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000020
>>
>>
>>>>> type string with no value at dataset=swift#mapper#17009 (not
>>>>>
>> closed)"
>>
>>>>> 2010-02-25 17:12:03,991-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> 2010-02-25 17:12:03,993-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000022
>>
>>
>>>>> 2010-02-25 17:12:03,997-0600 INFO AbstractDataNode Adding handle
>>>>> listener "modelOut.$[]/0" to
>>>>>
>> "org.griphyn.vdl.mapping.RootDataNode
>>
>>>>> identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000022
>>
>>
>>>>> type string with no value at dataset=swift#mapper#17011 (not
>>>>>
>> closed)"
>>
>>>>> 2010-02-25 17:12:03,997-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000023
>>
>>
>>>>> 2010-02-25 17:12:03,999-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000024
>>
>>
>>>>> 2010-02-25 17:12:04,001-0600 INFO AbstractDataNode Adding handle
>>>>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000025
>>
>>
>>>>> type LoopModelResults with no value at dataset=modelResults (not
>>>>> closed)" to "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000024
>>
>>
>>>>> type string with no value at dataset=swift#mapper#17013 (not
>>>>>
>> closed)"
>>
>>>>> 2010-02-25 17:12:04,001-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000025
>>
>>
>>>>> 2010-02-25 17:12:04,007-0600 INFO SetFieldValue Setting
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000018
>>
>>
>>>>> type string with no value at dataset=swift#mapper#17007 (not
>>>>>
>> closed)
>>
>>>>> to LoopModelIn.map
>>>>> 2010-02-25 17:12:04,007-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000026
>>
>>
>>>>> type string value=4 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:04,007-0600 INFO VDLFunction FUNCTION id=451000
>>>>> name=arg
>>>>>
>>>>>
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000026
>>
>>
>>>>> 2010-02-25 17:12:04,007-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451000
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000011
>>
>>
>>>>> name=name
>>>>> 2010-02-25 17:12:04,007-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451000
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000008
>>
>>
>>>>> name=value
>>>>> 2010-02-25 17:12:04,008-0600 INFO SetFieldValue Setting
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000020
>>
>>
>>>>> type string with no value at dataset=swift#mapper#17009 (not
>>>>>
>> closed)
>>
>>>>> to LoopModelData.map
>>>>> 2010-02-25 17:12:04,008-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>>
>> closed)"
>>
>>>>> about "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000020
>>
>>
>>>>> type string value=LoopModelData.map dataset=swift#mapper#17009
>>>>> (closed)"
>>>>> 2010-02-25 17:12:04,008-0600 INFO AbstractDataNode Adding handle
>>>>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>>
>> closed)" to
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000017
>>
>>
>>>>> type string with no value at dataset=outdir (not closed)"
>>>>> 2010-02-25 17:12:04,008-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000020
>>
>>
>>>>> type string value=LoopModelData.map dataset=swift#mapper#17009
>>>>> (closed)
>>>>> 2010-02-25 17:12:04,008-0600 INFO SetFieldValue Setting
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000022
>>
>>
>>>>> type string with no value at dataset=swift#mapper#17011 (not
>>>>>
>> closed)
>>
>>>>> to LoopModelOutArray.map
>>>>> 2010-02-25 17:12:04,009-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "modelOut.$[]/0" about "org.griphyn.vdl.mapping.RootDataNode
>>>>> identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000022
>>
>>
>>>>> type string value=LoopModelOutArray.map
>>>>>
>> dataset=swift#mapper#17011
>>
>>>>> (closed)"
>>>>> 2010-02-25 17:12:04,009-0600 INFO AbstractDataNode Adding handle
>>>>> listener "modelOut.$[]/0" to
>>>>>
>> "org.griphyn.vdl.mapping.RootDataNode
>>
>>>>> identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000014
>>
>>
>>>>> type int with no value at dataset=nSim (not closed)"
>>>>> 2010-02-25 17:12:04,009-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000022
>>
>>
>>>>> type string value=LoopModelOutArray.map
>>>>>
>> dataset=swift#mapper#17011
>>
>>>>> (closed)
>>>>> 2010-02-25 17:12:04,009-0600 INFO SetFieldValue Setting
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000024
>>
>>
>>>>> type string with no value at dataset=swift#mapper#17013 (not
>>>>>
>> closed)
>>
>>>>> to LoopModelResults.map
>>>>> 2010-02-25 17:12:04,009-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000025
>>
>>
>>>>> type LoopModelResults with no value at dataset=modelResults (not
>>>>> closed)" about "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000024
>>
>>
>>>>> type string value=LoopModelResults.map dataset=swift#mapper#17013
>>>>> (closed)"
>>>>> 2010-02-25 17:12:04,009-0600 INFO AbstractDataNode Adding handle
>>>>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000025
>>
>>
>>>>> type LoopModelResults with no value at dataset=modelResults (not
>>>>> closed)" to "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000017
>>
>>
>>>>> type string with no value at dataset=outdir (not closed)"
>>>>> 2010-02-25 17:12:04,009-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000024
>>
>>
>>>>> type string value=LoopModelResults.map dataset=swift#mapper#17013
>>>>> (closed)
>>>>> 2010-02-25 17:12:04,009-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000027
>>
>>
>>>>> type string value=T0510D1 dataset=unnamed SwiftScript value
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:04,009-0600 INFO VDLFunction FUNCTION id=451001
>>>>> name=arg
>>>>>
>>>>>
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000027
>>
>>
>>>>> 2010-02-25 17:12:04,010-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451001
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000006
>>
>>
>>>>> name=name
>>>>> 2010-02-25 17:12:04,010-0600 INFO SetFieldValue Setting
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000015
>>
>>
>>>>> type string with no value at dataset=proteinId (not closed) to
>>>>> T0510D1
>>>>> 2010-02-25 17:12:04,010-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000015
>>
>>
>>>>> type string value=T0510D1 dataset=proteinId (closed)
>>>>> 2010-02-25 17:12:04,010-0600 INFO CloseDataset Partially closing
>>>>> T0510D1 for statement 88013
>>>>> 2010-02-25 17:12:04,011-0600 INFO CloseDataset var is T0510D1
>>>>> 2010-02-25 17:12:04,011-0600 INFO CloseDataset var hash is
>>>>>
>> 28062585
>>
>>>>> 2010-02-25 17:12:04,011-0600 INFO CloseDataset variable already
>>>>> closed - skipping partial close processing
>>>>> 2010-02-25 17:12:04,011-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000028
>>
>>
>>>>> type string value=input dataset=unnamed SwiftScript value
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:04,011-0600 INFO VDLFunction FUNCTION id=451002
>>>>> name=arg
>>>>>
>>>>>
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000028
>>
>>
>>>>> 2010-02-25 17:12:04,011-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451002
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000003
>>
>>
>>>>> name=name
>>>>> 2010-02-25 17:12:04,011-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451002
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000001
>>
>>
>>>>> name=value
>>>>> 2010-02-25 17:12:04,011-0600 INFO SetFieldValue Setting
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000016
>>
>>
>>>>> type string with no value at dataset=indir (not closed) to input
>>>>> 2010-02-25 17:12:04,012-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000016
>>
>>
>>>>> type string value=input dataset=indir (closed)
>>>>> 2010-02-25 17:12:04,012-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000019
>>
>>
>>>>> type LoopModelIn with no value at dataset=modelIn (not closed)"
>>>>>
>> about
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000018
>>
>>
>>>>> type string value=LoopModelIn.map dataset=swift#mapper#17007
>>>>> (closed)"
>>>>> 2010-02-25 17:12:04,012-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000029
>>
>>
>>>>> type string value=output dataset=unnamed SwiftScript value
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:04,012-0600 INFO VDLFunction FUNCTION id=451003
>>>>> name=arg
>>>>>
>>>>>
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000029
>>
>>
>>>>> 2010-02-25 17:12:04,012-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451003
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000005
>>
>>
>>>>> name=name
>>>>> 2010-02-25 17:12:04,012-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451003
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000004
>>
>>
>>>>> name=value
>>>>> 2010-02-25 17:12:04,012-0600 INFO SetFieldValue Setting
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000017
>>
>>
>>>>> type string with no value at dataset=outdir (not closed) to
>>>>>
>> output
>>
>>>>> 2010-02-25 17:12:04,012-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>>
>> closed)"
>>
>>>>> about "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000017
>>
>>
>>>>> type string value=output dataset=outdir (closed)"
>>>>> 2010-02-25 17:12:04,027-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.DataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000030
>>
>>
>>>>> type PDB with no value at dataset=modelIn path=.pdb (closed)
>>>>> 2010-02-25 17:12:04,030-0600 INFO AbstractDataNode Found data
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000019
>>
>>
>>>>> type LoopModelIn with no value at dataset=modelIn (not
>>>>>
>> closed)..pdb
>>
>>>>> 2010-02-25 17:12:04,030-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.DataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000031
>>
>>
>>>>> type Text with no value at dataset=modelIn path=.params (closed)
>>>>> 2010-02-25 17:12:04,032-0600 INFO AbstractDataNode Found data
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000019
>>
>>
>>>>> type LoopModelIn with no value at dataset=modelIn (not
>>>>> closed)..params
>>>>> 2010-02-25 17:12:04,032-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.DataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000032
>>
>>
>>>>> type LoopRange with no value at dataset=modelIn path=.range
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:04,032-0600 INFO AbstractDataNode Found data
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000019
>>
>>
>>>>> type LoopModelIn with no value at dataset=modelIn (not
>>>>>
>> closed)..range
>>
>>>>> 2010-02-25 17:12:04,033-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000019
>>
>>
>>>>> type LoopModelIn with no value at dataset=modelIn (closed)
>>>>> 2010-02-25 17:12:04,033-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000018
>>
>>
>>>>> type string value=LoopModelIn.map dataset=swift#mapper#17007
>>>>>
>> (closed)
>>
>>>>> 2010-02-25 17:12:04,034-0600 INFO CloseDataset Partially closing
>>>>> input for statement 88014
>>>>> 2010-02-25 17:12:04,035-0600 INFO CloseDataset var is input
>>>>> 2010-02-25 17:12:04,035-0600 INFO CloseDataset var hash is
>>>>>
>> 21684929
>>
>>>>> 2010-02-25 17:12:04,035-0600 INFO CloseDataset variable already
>>>>> closed - skipping partial close processing
>>>>> 2010-02-25 17:12:04,040-0600 INFO loopprepare PROCEDURE line=112
>>>>> thread=0-1-8 name=loopPrepare
>>>>> 2010-02-25 17:12:04,041-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..fasta
>>>>> 2010-02-25 17:12:04,041-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..pdb
>>>>> 2010-02-25 17:12:04,041-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..native
>>>>> 2010-02-25 17:12:04,041-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..index
>>>>> 2010-02-25 17:12:04,041-0600 INFO strtoi STARTCOMPOUND
>>>>>
>> thread=0-1-0
>>
>>>>> name=strtoi
>>>>> 2010-02-25 17:12:04,041-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..params
>>>>> 2010-02-25 17:12:04,041-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..range
>>>>> 2010-02-25 17:12:04,042-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..rama
>>>>> 2010-02-25 17:12:04,042-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..map
>>>>> 2010-02-25 17:12:04,042-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000021
>>
>>
>>>>> type LoopModelData with no value at dataset=modelData (not
>>>>> closed)..secseq
>>>>> 2010-02-25 17:12:04,047-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000025
>>
>>
>>>>> type LoopModelResults with no value at dataset=modelResults (not
>>>>> closed)" about "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000017
>>
>>
>>>>> type string value=output dataset=outdir (closed)"
>>>>> 2010-02-25 17:12:04,051-0600 INFO loopmodelanalysis PROCEDURE
>>>>> line=122 thread=0-1-10 name=loopModelAnalysis
>>>>> 2010-02-25 17:12:04,053-0600 INFO doloopround STARTCOMPOUND
>>>>> thread=0-1-9 name=doLoopRound
>>>>> 2010-02-25 17:12:04,058-0600 INFO New NEW
>>>>>
>>>>>
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> 2010-02-25 17:12:04,058-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000025
>>
>>
>>>>> type LoopModelResults with no value at dataset=modelResults (not
>>>>> closed)..pwPlot
>>>>> 2010-02-25 17:12:04,058-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000025
>>
>>
>>>>> type LoopModelResults with no value at dataset=modelResults (not
>>>>> closed)..best
>>>>> 2010-02-25 17:12:04,059-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000025
>>
>>
>>>>> type LoopModelResults with no value at dataset=modelResults (not
>>>>> closed)..ligationPlot
>>>>> 2010-02-25 17:12:04,059-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000017
>>
>>
>>>>> type string value=output dataset=outdir (closed)
>>>>> 2010-02-25 17:12:04,059-0600 INFO CloseDataset Partially closing
>>>>> output for statement 88015
>>>>> 2010-02-25 17:12:04,059-0600 INFO CloseDataset var is output
>>>>> 2010-02-25 17:12:04,060-0600 INFO CloseDataset var hash is
>>>>>
>> 23848591
>>
>>>>> 2010-02-25 17:12:04,060-0600 INFO CloseDataset variable already
>>>>> closed - skipping partial close processing
>>>>> 2010-02-25 17:12:04,062-0600 INFO AbstractDataNode Adding handle
>>>>> listener "F/modelOut.$[]/0" to
>>>>> "org.griphyn.vdl.mapping.RootArrayDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000023
>>
>>
>>>>> type LoopModelOut[] with no value at dataset=modelOut (not
>>>>>
>> closed)"
>>
>>>>> 2010-02-25 17:12:04,062-0600 INFO AbstractDataNode Adding handle
>>>>> listener "F/org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000014
>>
>>
>>>>> type int with no value at dataset=nSim (not closed)" to
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000014
>>
>>
>>>>> type int with no value at dataset=nSim (not closed)"
>>>>> 2010-02-25 17:12:04,065-0600 INFO strtoi INTERNALPROC_START
>>>>> thread=0-1-0-1 name=readData
>>>>> 2010-02-25 17:12:04,068-0600 INFO AbstractDataNode Adding handle
>>>>> listener "F/org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> type file with no value at dataset=f (not closed)" to
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> type file with no value at dataset=f (not closed)"
>>>>> 2010-02-25 17:12:04,068-0600 INFO echos PROCEDURE line=68
>>>>> thread=0-1-0-0 name=echos
>>>>> 2010-02-25 17:12:04,077-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000046
>>
>>
>>>>> type string
>>>>> value=_concurrent/f-7a608b5e-b445-46f4-8cb2-bff8a73b52ec-1-0
>>>>> dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:04,077-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451004
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> name=input
>>>>> 2010-02-25 17:12:04,077-0600 INFO VDLFunction FUNCTION id=451004
>>>>> name=filename
>>>>>
>>>>>
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000046
>>
>>
>>>>> 2010-02-25 17:12:04,077-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000047
>>
>>
>>>>> type string value=input/T0510D1.pdb dataset=unnamed SwiftScript
>>>>>
>> value
>>
>>>>> (closed)
>>>>> 2010-02-25 17:12:04,078-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451005
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000030
>>
>>
>>>>> name=input
>>>>> 2010-02-25 17:12:04,078-0600 INFO VDLFunction FUNCTION id=451005
>>>>> name=filename
>>>>>
>>>>>
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000047
>>
>>
>>>>> 2010-02-25 17:12:04,078-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000048
>>
>>
>>>>> type string value=output/data//T0510D1.pdb dataset=unnamed
>>>>>
>> SwiftScript
>>
>>>>> value (closed)
>>>>> 2010-02-25 17:12:04,078-0600 INFO VDLFunction FUNCTIONPARAMETER
>>>>> id=451006
>>>>>
>>>>>
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000034
>>
>>
>>>>> name=input
>>>>> 2010-02-25 17:12:04,078-0600 INFO VDLFunction FUNCTION id=451006
>>>>> name=filename
>>>>>
>>>>>
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000048
>>
>>
>>>>> 2010-02-25 17:12:04,084-0600 INFO vdl:execute START
>>>>>
>> thread=0-1-0-0
>>
>>>>> tr=echo
>>>>> 2010-02-25 17:12:04,085-0600 INFO vdl:execute START thread=0-1-8
>>>>> tr=PrepLoop
>>>>> 2010-02-25 17:12:04,112-0600 INFO WeightedHostScoreScheduler
>>>>>
>> Sorted:
>>
>>>>> [localhost:10,000.000(99.854):0/3 overload: 0]
>>>>> 2010-02-25 17:12:04,112-0600 INFO WeightedHostScoreScheduler
>>>>> CONTACT_SELECTED host=localhost, score=99.854
>>>>> 2010-02-25 17:12:04,113-0600 INFO WeightedHostScoreScheduler
>>>>>
>> Sorted:
>>
>>>>> [localhost:10,000.000(99.854):1/3 overload: 0]
>>>>> 2010-02-25 17:12:04,114-0600 INFO WeightedHostScoreScheduler
>>>>> CONTACT_SELECTED host=localhost, score=99.854
>>>>> 2010-02-25 17:12:04,120-0600 INFO GlobalSubmitQueue No global
>>>>>
>> submit
>>
>>>>> throttle set. Using default (100)
>>>>> 2010-02-25 17:12:04,136-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524101) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,148-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524101) setting status to Submitted
>>>>> 2010-02-25 17:12:04,148-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524101) setting status to Active
>>>>> 2010-02-25 17:12:04,149-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524101) setting status to Completed
>>>>> 2010-02-25 17:12:04,149-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1267139524101)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,155-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524104) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,155-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524104) setting status to Submitted
>>>>> 2010-02-25 17:12:04,155-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524104) setting status to Active
>>>>> 2010-02-25 17:12:04,155-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524104) setting status to Completed
>>>>> 2010-02-25 17:12:04,155-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1267139524104)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,158-0600 INFO vdl:initshareddir START
>>>>> host=localhost - Initializing shared directory
>>>>> 2010-02-25 17:12:04,161-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524106) setting status to Submitting
>>>>> 2010-02-25 17:12:04,162-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524106) setting status to Submitted
>>>>> 2010-02-25 17:12:04,162-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524106) setting status to Active
>>>>> 2010-02-25 17:12:04,163-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524106) setting status to Completed
>>>>> 2010-02-25 17:12:04,163-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1267139524106)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,185-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1267139524109) setting status to Submitting
>>>>> 2010-02-25 17:12:04,185-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1267139524109) setting status to Submitted
>>>>> 2010-02-25 17:12:04,187-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1267139524109) setting status to Active
>>>>> 2010-02-25 17:12:04,190-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1267139524109) setting status to Completed
>>>>> 2010-02-25 17:12:04,190-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-1267139524109)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,191-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1267139524112) setting status to Submitting
>>>>> 2010-02-25 17:12:04,191-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1267139524112) setting status to Submitted
>>>>> 2010-02-25 17:12:04,191-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1267139524112) setting status to Active
>>>>> 2010-02-25 17:12:04,236-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1267139524112) setting status to Completed
>>>>> 2010-02-25 17:12:04,236-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-1267139524112)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,237-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524115) setting status to Submitting
>>>>> 2010-02-25 17:12:04,237-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524115) setting status to Submitted
>>>>> 2010-02-25 17:12:04,237-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524115) setting status to Active
>>>>> 2010-02-25 17:12:04,238-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524115) setting status to Completed
>>>>> 2010-02-25 17:12:04,238-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1267139524115)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,239-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524117) setting status to Submitting
>>>>> 2010-02-25 17:12:04,239-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524117) setting status to Submitted
>>>>> 2010-02-25 17:12:04,239-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524117) setting status to Active
>>>>> 2010-02-25 17:12:04,240-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524117) setting status to Completed
>>>>> 2010-02-25 17:12:04,240-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1267139524117)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,241-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524119) setting status to Submitting
>>>>> 2010-02-25 17:12:04,244-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524119) setting status to Submitted
>>>>> 2010-02-25 17:12:04,244-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524119) setting status to Active
>>>>> 2010-02-25 17:12:04,244-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524119) setting status to Completed
>>>>> 2010-02-25 17:12:04,244-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1267139524119)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,245-0600 INFO vdl:initshareddir END
>>>>> host=localhost - Done initializing shared directory
>>>>> 2010-02-25 17:12:04,248-0600 DEBUG vdl:execute2
>>>>>
>> THREAD_ASSOCIATION
>>
>>>>> jobid=echo-xkjtxaoj thread=0-1-0-0-1 host=localhost
>>>>> replicationGroup=ukjtxaoj
>>>>> 2010-02-25 17:12:04,250-0600 DEBUG vdl:execute2
>>>>>
>> THREAD_ASSOCIATION
>>
>>>>> jobid=PrepLoop-ykjtxaoj thread=0-1-8-1 host=localhost
>>>>> replicationGroup=vkjtxaoj
>>>>> 2010-02-25 17:12:04,255-0600 INFO vdl:createdirset START
>>>>> jobid=echo-xkjtxaoj host=localhost - Initializing directory
>>>>>
>> structure
>>
>>>>> 2010-02-25 17:12:04,257-0600 INFO vdl:createdirs START
>>>>> path=_concurrent dir=psim.loops-20100225-1712-3zrtb5i5/shared -
>>>>> Creating directory structure
>>>>> 2010-02-25 17:12:04,257-0600 INFO vdl:createdirset START
>>>>> jobid=PrepLoop-ykjtxaoj host=localhost - Initializing directory
>>>>> structure
>>>>> 2010-02-25 17:12:04,258-0600 INFO vdl:createdirs START
>>>>>
>> path=input
>>
>>>>> dir=psim.loops-20100225-1712-3zrtb5i5/shared - Creating directory
>>>>> structure
>>>>> 2010-02-25 17:12:04,258-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524121) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,258-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524121) setting status to Submitted
>>>>> 2010-02-25 17:12:04,258-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524121) setting status to Active
>>>>> 2010-02-25 17:12:04,259-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524123) setting status to Submitting
>>>>> 2010-02-25 17:12:04,259-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524123) setting status to Submitted
>>>>> 2010-02-25 17:12:04,259-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524123) setting status to Active
>>>>> 2010-02-25 17:12:04,261-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524121) setting status to Completed
>>>>> 2010-02-25 17:12:04,261-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524123) setting status to Completed
>>>>> 2010-02-25 17:12:04,261-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1267139524121)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,262-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1267139524123)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,262-0600 INFO vdl:createdirset END
>>>>> jobid=echo-xkjtxaoj - Done initializing directory structure
>>>>> 2010-02-25 17:12:04,263-0600 INFO vdl:createdirs START
>>>>> path=output/data/ dir=psim.loops-20100225-1712-3zrtb5i5/shared -
>>>>> Creating directory structure
>>>>> 2010-02-25 17:12:04,263-0600 INFO vdl:dostagein START
>>>>> jobid=echo-xkjtxaoj - Staging in files
>>>>> 2010-02-25 17:12:04,263-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524126) setting status to Submitting
>>>>> 2010-02-25 17:12:04,263-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524126) setting status to Submitted
>>>>> 2010-02-25 17:12:04,264-0600 INFO vdl:dostagein END
>>>>> jobid=echo-xkjtxaoj - Staging in finished
>>>>> 2010-02-25 17:12:04,269-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524126) setting status to Active
>>>>> 2010-02-25 17:12:04,274-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524126) setting status to Completed
>>>>> 2010-02-25 17:12:04,274-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1267139524126)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,275-0600 DEBUG vdl:execute2 JOB_START
>>>>> jobid=echo-xkjtxaoj tr=echo arguments=[4]
>>>>> tmpdir=psim.loops-20100225-1712-3zrtb5i5/jobs/x/echo-xkjtxaoj
>>>>> host=localhost
>>>>> 2010-02-25 17:12:04,275-0600 INFO vdl:createdirs START path=
>>>>> dir=psim.loops-20100225-1712-3zrtb5i5/shared - Creating directory
>>>>> structure
>>>>> 2010-02-25 17:12:04,276-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524128) setting status to Submitting
>>>>> 2010-02-25 17:12:04,276-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524128) setting status to Submitted
>>>>> 2010-02-25 17:12:04,276-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524128) setting status to Active
>>>>> 2010-02-25 17:12:04,276-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524128) setting status to Completed
>>>>> 2010-02-25 17:12:04,276-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1267139524128)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,277-0600 INFO vdl:createdirset END
>>>>> jobid=PrepLoop-ykjtxaoj - Done initializing directory structure
>>>>> 2010-02-25 17:12:04,278-0600 INFO vdl:dostagein START
>>>>> jobid=PrepLoop-ykjtxaoj - Staging in files
>>>>> 2010-02-25 17:12:04,283-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524131) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,283-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524131) setting status to Submitted
>>>>> 2010-02-25 17:12:04,283-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524131) setting status to Active
>>>>> 2010-02-25 17:12:04,284-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524132) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,285-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524132) setting status to Submitted
>>>>> 2010-02-25 17:12:04,287-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524132) setting status to Active
>>>>> 2010-02-25 17:12:04,288-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524131) setting status to Completed
>>>>> 2010-02-25 17:12:04,288-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1-1267139524131)
>>>>> Completed. Waiting: 0, Running: 2. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,289-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524132) setting status to Completed
>>>>> 2010-02-25 17:12:04,289-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-3-1267139524132)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,290-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524134) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,290-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524134) setting status to Submitted
>>>>> 2010-02-25 17:12:04,290-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524134) setting status to Active
>>>>> 2010-02-25 17:12:04,291-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524134) setting status to Completed
>>>>> 2010-02-25 17:12:04,291-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-2-1267139524134)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,295-0600 INFO Execute jobid=echo-xkjtxaoj
>>>>> task=Task(type=JOB_SUBMISSION,
>>>>>
>> identity=urn:0-1-0-0-1-1267139524137)
>>
>>>>> 2010-02-25 17:12:04,303-0600 DEBUG vdl:dostagein
>>>>>
>> FILE_STAGE_IN_START
>>
>>>>> file=file://localhost/input/T0510D1.range srchost=localhost
>>>>> srcdir=input srcname=T0510D1.range desthost=localhost
>>>>> destdir=psim.loops-20100225-1712-3zrtb5i5/shared/input
>>>>>
>> provider=file
>>
>>>>> 2010-02-25 17:12:04,304-0600 DEBUG vdl:dostagein
>>>>>
>> FILE_STAGE_IN_START
>>
>>>>> file=file://localhost/input/T0510D1.params srchost=localhost
>>>>> srcdir=input srcname=T0510D1.params desthost=localhost
>>>>> destdir=psim.loops-20100225-1712-3zrtb5i5/shared/input
>>>>>
>> provider=file
>>
>>>>> 2010-02-25 17:12:04,305-0600 DEBUG vdl:dostagein
>>>>>
>> FILE_STAGE_IN_START
>>
>>>>> file=file://localhost/input/T0510D1.pdb srchost=localhost
>>>>>
>> srcdir=input
>>
>>>>> srcname=T0510D1.pdb desthost=localhost
>>>>> destdir=psim.loops-20100225-1712-3zrtb5i5/shared/input
>>>>>
>> provider=file
>>
>>>>> 2010-02-25 17:12:04,305-0600 DEBUG TaskImpl
>>>>>
>> Task(type=JOB_SUBMISSION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524137) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,305-0600 INFO JobSubmissionTaskHandler
>>>>>
>> Submitting
>>
>>>>> task Task(type=JOB_SUBMISSION,
>>>>>
>> identity=urn:0-1-0-0-1-1267139524137)
>>
>>>>> 2010-02-25 17:12:04,305-0600 INFO JobSubmissionTaskHandler
>>>>>
>> Submitting
>>
>>>>> single job
>>>>> 2010-02-25 17:12:04,306-0600 DEBUG TaskImpl
>>>>>
>> Task(type=JOB_SUBMISSION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524137) setting status to Submitted
>>>>> 2010-02-25 17:12:04,306-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524141) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,306-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524141) setting status to Submitted
>>>>> 2010-02-25 17:12:04,306-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524139) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,306-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524139) setting status to Submitted
>>>>> 2010-02-25 17:12:04,307-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524141) setting status to Active
>>>>> 2010-02-25 17:12:04,307-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524139) setting status to Active
>>>>> 2010-02-25 17:12:04,308-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524143) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,308-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524143) setting status to Submitted
>>>>> 2010-02-25 17:12:04,312-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524139) setting status to Completed
>>>>> 2010-02-25 17:12:04,312-0600 DEBUG TaskImpl
>>>>>
>> Task(type=JOB_SUBMISSION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524137) setting status to Active
>>>>> 2010-02-25 17:12:04,313-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-2-1267139524139)
>>>>> Completed. Waiting: 0, Running: 3. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,321-0600 DEBUG vdl:dostagein
>>>>>
>> FILE_STAGE_IN_END
>>
>>>>> file=file://localhost/input/T0510D1.range srchost=localhost
>>>>> srcdir=input srcname=T0510D1.range desthost=localhost
>>>>> destdir=psim.loops-20100225-1712-3zrtb5i5/shared/input
>>>>>
>> provider=file
>>
>>>>> 2010-02-25 17:12:04,323-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524141) setting status to Completed
>>>>> 2010-02-25 17:12:04,324-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-1-1267139524141)
>>>>> Completed. Waiting: 0, Running: 2. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,325-0600 DEBUG vdl:dostagein
>>>>>
>> FILE_STAGE_IN_END
>>
>>>>> file=file://localhost/input/T0510D1.params srchost=localhost
>>>>> srcdir=input srcname=T0510D1.params desthost=localhost
>>>>> destdir=psim.loops-20100225-1712-3zrtb5i5/shared/input
>>>>>
>> provider=file
>>
>>>>> 2010-02-25 17:12:04,325-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524143) setting status to Active
>>>>> 2010-02-25 17:12:04,327-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524143) setting status to Completed
>>>>> 2010-02-25 17:12:04,327-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-3-1267139524143)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,327-0600 DEBUG vdl:dostagein
>>>>>
>> FILE_STAGE_IN_END
>>
>>>>> file=file://localhost/input/T0510D1.pdb srchost=localhost
>>>>>
>> srcdir=input
>>
>>>>> srcname=T0510D1.pdb desthost=localhost
>>>>> destdir=psim.loops-20100225-1712-3zrtb5i5/shared/input
>>>>>
>> provider=file
>>
>>>>> 2010-02-25 17:12:04,327-0600 INFO vdl:dostagein END
>>>>> jobid=PrepLoop-ykjtxaoj - Staging in finished
>>>>> 2010-02-25 17:12:04,328-0600 DEBUG vdl:execute2 JOB_START
>>>>> jobid=PrepLoop-ykjtxaoj tr=PrepLoop arguments=[input/T0510D1.pdb,
>>>>> output/data//T0510D1.pdb]
>>>>> tmpdir=psim.loops-20100225-1712-3zrtb5i5/jobs/y/PrepLoop-ykjtxaoj
>>>>> host=localhost
>>>>> 2010-02-25 17:12:04,339-0600 INFO Execute
>>>>>
>> jobid=PrepLoop-ykjtxaoj
>>
>>>>> task=Task(type=JOB_SUBMISSION,
>>>>>
>> identity=urn:0-1-8-1-1267139524148)
>>
>>>>> 2010-02-25 17:12:04,340-0600 DEBUG TaskImpl
>>>>>
>> Task(type=JOB_SUBMISSION,
>>
>>>>> identity=urn:0-1-8-1-1267139524148) setting status to Submitting
>>>>> 2010-02-25 17:12:04,340-0600 INFO JobSubmissionTaskHandler
>>>>>
>> Submitting
>>
>>>>> task Task(type=JOB_SUBMISSION,
>>>>>
>> identity=urn:0-1-8-1-1267139524148)
>>
>>>>> 2010-02-25 17:12:04,340-0600 INFO JobSubmissionTaskHandler
>>>>>
>> Submitting
>>
>>>>> single job
>>>>> 2010-02-25 17:12:04,340-0600 DEBUG TaskImpl
>>>>>
>> Task(type=JOB_SUBMISSION,
>>
>>>>> identity=urn:0-1-8-1-1267139524148) setting status to Submitted
>>>>> 2010-02-25 17:12:04,343-0600 DEBUG TaskImpl
>>>>>
>> Task(type=JOB_SUBMISSION,
>>
>>>>> identity=urn:0-1-8-1-1267139524148) setting status to Active
>>>>> 2010-02-25 17:12:04,458-0600 DEBUG TaskImpl
>>>>>
>> Task(type=JOB_SUBMISSION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524137) setting status to Completed
>>>>> 2010-02-25 17:12:04,459-0600 INFO LateBindingScheduler
>>>>> Task(type=JOB_SUBMISSION, identity=urn:0-1-0-0-1-1267139524137)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,460-0600 DEBUG vdl:checkjobstatus START
>>>>> jobid=echo-xkjtxaoj
>>>>> 2010-02-25 17:12:04,461-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524150) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,462-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524150) setting status to Submitted
>>>>> 2010-02-25 17:12:04,462-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524150) setting status to Active
>>>>> 2010-02-25 17:12:04,462-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1267139524150) setting status to Completed
>>>>> 2010-02-25 17:12:04,462-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1267139524150)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,463-0600 INFO vdl:checkjobstatus SUCCESS
>>>>> jobid=echo-xkjtxaoj - Success file found
>>>>> 2010-02-25 17:12:04,463-0600 DEBUG vdl:execute2 STAGING_OUT
>>>>> jobid=echo-xkjtxaoj
>>>>> 2010-02-25 17:12:04,464-0600 INFO vdl:dostageout START
>>>>> jobid=echo-xkjtxaoj - Staging out files
>>>>> 2010-02-25 17:12:04,470-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=f-7a608b5e-b445-46f4-8cb2-bff8a73b52ec-1-0
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/_concurrent
>>>>> srchost=localhost destdir=_concurrent desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:04,471-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524152) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,471-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524152) setting status to
>>>>>
>> Submitted
>>
>>>>> 2010-02-25 17:12:04,471-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524152) setting status to Active
>>>>> 2010-02-25 17:12:04,471-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524152) setting status to
>>>>>
>> Completed
>>
>>>>> 2010-02-25 17:12:04,471-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1-1267139524152)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,473-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524154) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,473-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524154) setting status to
>>>>>
>> Submitted
>>
>>>>> 2010-02-25 17:12:04,473-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524154) setting status to Active
>>>>> 2010-02-25 17:12:04,474-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524154) setting status to
>>>>>
>> Completed
>>
>>>>> 2010-02-25 17:12:04,474-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-0-0-1-1-1267139524154)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,474-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_END
>>
>>>>> srcname=f-7a608b5e-b445-46f4-8cb2-bff8a73b52ec-1-0
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/_concurrent
>>>>> srchost=localhost destdir=_concurrent desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:04,475-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524157) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:04,475-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524157) setting status to
>>>>>
>> Submitted
>>
>>>>> 2010-02-25 17:12:04,475-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524157) setting status to Active
>>>>> 2010-02-25 17:12:04,476-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-0-0-1-1-1267139524157) setting status to
>>>>>
>> Completed
>>
>>>>> 2010-02-25 17:12:04,476-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1-1267139524157)
>>>>> Completed. Waiting: 0, Running: 1. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:04,479-0600 INFO vdl:dostageout END
>>>>> jobid=echo-xkjtxaoj - Staging out finished
>>>>> 2010-02-25 17:12:04,482-0600 DEBUG vdl:execute2 JOB_END
>>>>> jobid=echo-xkjtxaoj
>>>>> 2010-02-25 17:12:04,484-0600 INFO vdl:execute END_SUCCESS
>>>>> thread=0-1-0-0 tr=echo
>>>>> 2010-02-25 17:12:04,613-0600 INFO CloseDataset Closing
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> type file with no value at dataset=f (not closed)
>>>>> 2010-02-25 17:12:04,614-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "F/org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> type file with no value at dataset=f (closed)" about
>>>>> "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> type file with no value at dataset=f (closed)"
>>>>> 2010-02-25 17:12:04,614-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> type file with no value at dataset=f (closed)
>>>>> 2010-02-25 17:12:04,614-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "modelOut.$[]/0" about "org.griphyn.vdl.mapping.RootDataNode
>>>>> identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000014
>>
>>
>>>>> type int value=4.0 dataset=nSim (closed)"
>>>>> 2010-02-25 17:12:04,615-0600 INFO echos PROCEDURE_END line=68
>>>>> 2010-02-25 17:12:04,615-0600 INFO CloseDataset Partially closing
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> type file with no value at dataset=f (closed) for statement 88004
>>>>> 2010-02-25 17:12:04,615-0600 INFO CloseDataset var is
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000042
>>
>>
>>>>> type file with no value at dataset=f (closed)
>>>>> 2010-02-25 17:12:04,615-0600 INFO CloseDataset var hash is
>>>>>
>> 21621663
>>
>>>>> 2010-02-25 17:12:04,615-0600 INFO CloseDataset variable already
>>>>> closed - skipping partial close processing
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/1.[2].pdt
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/2.[0].cfg
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/3.[1].cfg
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[3].log
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[3].cfg
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[3].pdt
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[0].pdt
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[1].pdb
>>>>> 2010-02-25 17:12:04,682-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[0].log
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[1].log
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[2].cfg
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[2].log
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[3].pdb
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[2].pdb
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[1].pdt
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode Found mapped
>>>>>
>> data
>>
>>>>> modelOut.$[]/4.[0].pdb
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "F/modelOut.$[]/4" about
>>>>>
>> "org.griphyn.vdl.mapping.RootArrayDataNode
>>
>>>>> identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000023
>>
>>
>>>>> type LoopModelOut[] with no value at dataset=modelOut (closed)"
>>>>> 2010-02-25 17:12:04,683-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootArrayDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000023
>>
>>
>>>>> type LoopModelOut[] with no value at dataset=modelOut (closed)
>>>>> 2010-02-25 17:12:04,684-0600 INFO AbstractDataNode Notifying
>>>>>
>> listener
>>
>>>>> "F/4" about "org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000014
>>
>>
>>>>> type int value=4.0 dataset=nSim (closed)"
>>>>> 2010-02-25 17:12:04,684-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000014
>>
>>
>>>>> type int value=4.0 dataset=nSim (closed)
>>>>> 2010-02-25 17:12:04,685-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000069
>>
>>
>>>>> type int value=3.0 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:04,685-0600 INFO strtoi INTERNALPROC_END
>>>>> thread=0-1-0-1
>>>>> 2010-02-25 17:12:04,685-0600 INFO CloseDataset Closing 4
>>>>> 2010-02-25 17:12:04,686-0600 INFO strtoi ENDCOMPOUND
>>>>>
>> thread=0-1-0
>>
>>>>> 2010-02-25 17:12:04,686-0600 INFO CloseDataset Partially closing
>>>>>
>> 4
>>
>>>>> for statement 88012
>>>>> 2010-02-25 17:12:04,686-0600 INFO CloseDataset var is 4
>>>>> 2010-02-25 17:12:04,686-0600 INFO CloseDataset var hash is
>>>>>
>> 2221396
>>
>>>>> 2010-02-25 17:12:04,687-0600 INFO CloseDataset variable already
>>>>> closed - skipping partial close processing
>>>>> 2010-02-25 17:12:04,687-0600 INFO AbstractDataNode Adding handle
>>>>> listener "F/org.griphyn.vdl.mapping.DataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000056
>>
>>
>>>>> type ModelLog with no value at dataset=modelOut path=[3].log (not
>>>>> closed)" to "org.griphyn.vdl.mapping.DataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000056
>>
>>
>>>>> type ModelLog with no value at dataset=modelOut path=[3].log (not
>>>>> closed)"
>>>>> 2010-02-25 17:12:04,700-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000071
>>
>>
>>>>> type int value=0.0 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:04,701-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000072
>>
>>
>>>>> type int value=1.0 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:04,701-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000073
>>
>>
>>>>> type int value=2.0 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:04,701-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.mapping.RootDataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000074
>>
>>
>>>>> type int value=3.0 dataset=unnamed SwiftScript value (closed)
>>>>> 2010-02-25 17:12:04,701-0600 INFO AbstractDataNode closed
>>>>> org.griphyn.vdl.karajan.lib.Range$1 identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000070
>>
>>
>>>>> type int[] with no value at dataset=unnamed SwiftScript value
>>>>> (closed)
>>>>> 2010-02-25 17:12:04,702-0600 INFO doloopround FOREACH_IT_START
>>>>> line=130 thread=0-1-9-1-1
>>>>> 2010-02-25 17:12:04,703-0600 INFO doloopround FOREACH_IT_START
>>>>> line=130 thread=0-1-9-1-2
>>>>> 2010-02-25 17:12:04,703-0600 INFO doloopround FOREACH_IT_START
>>>>> line=130 thread=0-1-9-1-3
>>>>> 2010-02-25 17:12:04,703-0600 INFO doloopround FOREACH_IT_START
>>>>> line=130 thread=0-1-9-1-4
>>>>> 2010-02-25 17:12:04,703-0600 INFO doloopround SCOPE
>>>>>
>> thread=0-1-9-1-2
>>
>>>>> 2010-02-25 17:12:04,703-0600 INFO doloopround SCOPE
>>>>>
>> thread=0-1-9-1-3
>>
>>>>> 2010-02-25 17:12:04,704-0600 INFO doloopround SCOPE
>>>>>
>> thread=0-1-9-1-4
>>
>>>>> 2010-02-25 17:12:04,707-0600 INFO loopmodel PROCEDURE line=117
>>>>> thread=0-1-9-1-2-1 name=loopModel
>>>>> 2010-02-25 17:12:04,707-0600 INFO loopmodel PROCEDURE line=117
>>>>> thread=0-1-9-1-3-1 name=loopModel
>>>>> 2010-02-25 17:12:04,708-0600 INFO loopmodel PROCEDURE line=117
>>>>> thread=0-1-9-1-4-1 name=loopModel
>>>>> 2010-02-25 17:12:04,710-0600 INFO AbstractDataNode Adding handle
>>>>> listener "F/org.griphyn.vdl.mapping.DataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000036
>>
>>
>>>>> type RamaIndex with no value at dataset=modelData path=.index
>>>>>
>> (not
>>
>>>>> closed)" to "org.griphyn.vdl.mapping.DataNode identifier
>>>>>
>>>>>
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100225-1712-kjif48ad:720000000036
>>
>>
>>>>> type RamaIndex with no value at dataset=modelData path=.index
>>>>>
>> (not
>>
>>>>> closed)"
>>>>> 2010-02-25 17:12:04,711-0600 INFO doloopround SCOPE
>>>>>
>> thread=0-1-9-1-1
>>
>>>>> 2010-02-25 17:12:04,712-0600 INFO loopmodel PROCEDURE line=117
>>>>> thread=0-1-9-1-1-1 name=loopModel
>>>>> 2010-02-25 17:12:16,434-0600 DEBUG TaskImpl
>>>>>
>> Task(type=JOB_SUBMISSION,
>>
>>>>> identity=urn:0-1-8-1-1267139524148) setting status to Completed
>>>>> 2010-02-25 17:12:16,434-0600 INFO LateBindingScheduler
>>>>> Task(type=JOB_SUBMISSION, identity=urn:0-1-8-1-1267139524148)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,436-0600 DEBUG vdl:checkjobstatus START
>>>>> jobid=PrepLoop-ykjtxaoj
>>>>> 2010-02-25 17:12:16,444-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524159) setting status to Submitting
>>>>> 2010-02-25 17:12:16,444-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524159) setting status to Submitted
>>>>> 2010-02-25 17:12:16,444-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524159) setting status to Active
>>>>> 2010-02-25 17:12:16,444-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1267139524159) setting status to Completed
>>>>> 2010-02-25 17:12:16,444-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1267139524159)
>>>>> Completed. Waiting: 0, Running: 0. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,445-0600 INFO vdl:checkjobstatus SUCCESS
>>>>> jobid=PrepLoop-ykjtxaoj - Success file found
>>>>> 2010-02-25 17:12:16,447-0600 DEBUG vdl:execute2 STAGING_OUT
>>>>> jobid=PrepLoop-ykjtxaoj
>>>>> 2010-02-25 17:12:16,447-0600 INFO vdl:dostageout START
>>>>> jobid=PrepLoop-ykjtxaoj - Staging out files
>>>>> 2010-02-25 17:12:16,454-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=T0510D1.rama_index
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,454-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=T0510D1.secseq
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,455-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=T0510D1.params
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,456-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=T0510D1.rama
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,456-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=T0510D1.rama_map
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,456-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=T0510D1.fasta
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,457-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=T0510D1.range
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,457-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=T0510D1.pdb
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,457-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524162) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,458-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524162) setting status to Submitted
>>>>> 2010-02-25 17:12:16,458-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524162) setting status to Active
>>>>> 2010-02-25 17:12:16,458-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524162) setting status to Completed
>>>>> 2010-02-25 17:12:16,458-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1-1267139524162)
>>>>> Completed. Waiting: 2, Running: 3. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,458-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_START
>>
>>>>> srcname=void srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/
>>>>> srchost=localhost destdir= desthost=localhost provider=file
>>>>> 2010-02-25 17:12:16,458-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524164) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,459-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524164) setting status to Submitted
>>>>> 2010-02-25 17:12:16,459-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524165) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,459-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524165) setting status to Submitted
>>>>> 2010-02-25 17:12:16,459-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524165) setting status to Active
>>>>> 2010-02-25 17:12:16,459-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524165) setting status to Completed
>>>>> 2010-02-25 17:12:16,459-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-3-1267139524165)
>>>>> Completed. Waiting: 0, Running: 8. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,459-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524164) setting status to Active
>>>>> 2010-02-25 17:12:16,459-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524164) setting status to Completed
>>>>> 2010-02-25 17:12:16,460-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-2-1267139524164)
>>>>> Completed. Waiting: 0, Running: 7. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,460-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-7-1267139524167) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,461-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-7-1267139524167) setting status to Submitted
>>>>> 2010-02-25 17:12:16,461-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-7-1267139524167) setting status to Active
>>>>> 2010-02-25 17:12:16,461-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-7-1267139524167) setting status to Completed
>>>>> 2010-02-25 17:12:16,461-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-7-1267139524167)
>>>>> Completed. Waiting: 0, Running: 8. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,462-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524171) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,462-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524171) setting status to Submitted
>>>>> 2010-02-25 17:12:16,462-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524171) setting status to Active
>>>>> 2010-02-25 17:12:16,466-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524173) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,466-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524173) setting status to Submitted
>>>>> 2010-02-25 17:12:16,466-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524173) setting status to Active
>>>>> 2010-02-25 17:12:16,466-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524173) setting status to Completed
>>>>> 2010-02-25 17:12:16,466-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-6-1267139524173)
>>>>> Completed. Waiting: 0, Running: 8. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,467-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524171) setting status to Completed
>>>>> 2010-02-25 17:12:16,467-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-8-1267139524171)
>>>>> Completed. Waiting: 0, Running: 7. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,467-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-9-1267139524175) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,467-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-9-1267139524175) setting status to Submitted
>>>>> 2010-02-25 17:12:16,467-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-9-1267139524175) setting status to Active
>>>>> 2010-02-25 17:12:16,467-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-9-1267139524175) setting status to Completed
>>>>> 2010-02-25 17:12:16,467-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-9-1267139524175)
>>>>> Completed. Waiting: 1, Running: 6. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,468-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-5-1267139524169) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,468-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-5-1267139524169) setting status to Submitted
>>>>> 2010-02-25 17:12:16,468-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-5-1267139524169) setting status to Active
>>>>> 2010-02-25 17:12:16,468-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-5-1267139524169) setting status to Completed
>>>>> 2010-02-25 17:12:16,468-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-5-1267139524169)
>>>>> Completed. Waiting: 3, Running: 5. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,469-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-4-1267139524177) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,469-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-4-1267139524177) setting status to Submitted
>>>>> 2010-02-25 17:12:16,469-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-4-1267139524177) setting status to Active
>>>>> 2010-02-25 17:12:16,469-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-4-1267139524177) setting status to Completed
>>>>> 2010-02-25 17:12:16,469-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-4-1267139524177)
>>>>> Completed. Waiting: 4, Running: 4. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,469-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524181) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,470-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524181) setting status to Submitted
>>>>> 2010-02-25 17:12:16,470-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524179) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,470-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524179) setting status to Submitted
>>>>> 2010-02-25 17:12:16,470-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524183) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,470-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524183) setting status to Submitted
>>>>> 2010-02-25 17:12:16,470-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524183) setting status to Active
>>>>> 2010-02-25 17:12:16,471-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524183) setting status to Completed
>>>>> 2010-02-25 17:12:16,471-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-2-1267139524183)
>>>>> Completed. Waiting: 5, Running: 3. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,471-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-7-1267139524185) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,471-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-7-1267139524185) setting status to Submitted
>>>>> 2010-02-25 17:12:16,471-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_END
>>
>>>>> srcname=T0510D1.secseq
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,472-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524187) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,472-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524187) setting status to Submitted
>>>>> 2010-02-25 17:12:16,472-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-2-1267139524198) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,472-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524187) setting status to Active
>>>>> 2010-02-25 17:12:16,472-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-1-1267139524179) setting status to Active
>>>>> 2010-02-25 17:12:16,473-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524187) setting status to Completed
>>>>> 2010-02-25 17:12:16,473-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-6-1267139524187)
>>>>> Completed. Waiting: 4, Running: 4. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,473-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524181) setting status to Active
>>>>> 2010-02-25 17:12:16,474-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524181) setting status to Completed
>>>>> 2010-02-25 17:12:16,474-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-3-1267139524181)
>>>>> Completed. Waiting: 4, Running: 3. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,475-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_END
>>
>>>>> srcname=T0510D1.range
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,475-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_END
>>
>>>>> srcname=T0510D1.params
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,476-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524203) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,476-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524203) setting status to Submitted
>>>>> 2010-02-25 17:12:16,476-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524203) setting status to Active
>>>>> 2010-02-25 17:12:16,476-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-6-1267139524203) setting status to Completed
>>>>> 2010-02-25 17:12:16,477-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-6-1267139524203)
>>>>> Completed. Waiting: 2, Running: 6. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,477-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524205) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,477-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524205) setting status to Submitted
>>>>> 2010-02-25 17:12:16,477-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524205) setting status to Active
>>>>> 2010-02-25 17:12:16,477-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-3-1267139524205) setting status to Completed
>>>>> 2010-02-25 17:12:16,477-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-3-1267139524205)
>>>>> Completed. Waiting: 2, Running: 5. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,478-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524191) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,478-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524191) setting status to Submitted
>>>>> 2010-02-25 17:12:16,478-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-9-1267139524189) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,478-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-9-1267139524189) setting status to Submitted
>>>>> 2010-02-25 17:12:16,478-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524191) setting status to Active
>>>>> 2010-02-25 17:12:16,479-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524191) setting status to Completed
>>>>> 2010-02-25 17:12:16,479-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-8-1267139524191)
>>>>> Completed. Waiting: 2, Running: 4. Heap size: 14M, Heap free: 5M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,479-0600 DEBUG vdl:dostageout
>>>>>
>> FILE_STAGE_OUT_END
>>
>>>>> srcname=T0510D1.fasta
>>>>> srcdir=psim.loops-20100225-1712-3zrtb5i5/shared/output/data/
>>>>> srchost=localhost destdir=output/data/ desthost=localhost
>>>>> provider=file
>>>>> 2010-02-25 17:12:16,480-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524208) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,480-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524208) setting status to Submitted
>>>>> 2010-02-25 17:12:16,480-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524208) setting status to Active
>>>>> 2010-02-25 17:12:16,481-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_OPERATION,
>>
>>>>> identity=urn:0-1-8-1-8-1267139524208) setting status to Completed
>>>>> 2010-02-25 17:12:16,481-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-8-1267139524208)
>>>>> Completed. Waiting: 1, Running: 5. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,482-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-5-1267139524193) setting status to
>>>>>
>> Submitting
>>
>>>>> 2010-02-25 17:12:16,482-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-5-1267139524193) setting status to Submitted
>>>>> 2010-02-25 17:12:16,483-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-5-1267139524193) setting status to Active
>>>>> 2010-02-25 17:12:16,488-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-9-1267139524189) setting status to Active
>>>>> 2010-02-25 17:12:16,489-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-9-1267139524189) setting status to Completed
>>>>> 2010-02-25 17:12:16,489-0600 INFO LateBindingScheduler
>>>>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-9-1267139524189)
>>>>> Completed. Waiting: 1, Running: 4. Heap size: 14M, Heap free: 4M,
>>>>>
>> Max
>>
>>>>> heap: 254M
>>>>> 2010-02-25 17:12:16,490-0600 DEBUG TaskImpl
>>>>>
>> Task(type=FILE_TRANSFER,
>>
>>>>> identity=urn:0-1-8-1-4-1267139524195) setting st
>>>>>
>> 2010-03-11 11:32:36,651-0600 DEBUG Loader Max heap: 266403840
>> 2010-03-11 11:32:36,652-0600 DEBUG Loader kmlversion is
>>
>>> 783e9459-e981-4366-83ed-a7fe256e5175<
>>>
>> 2010-03-11 11:32:36,652-0600 DEBUG Loader build version is
>>
>>> 783e9459-e981-4366-83ed-a7fe256e5175<
>>>
>> 2010-03-11 11:32:36,652-0600 DEBUG Loader Recompilation suppressed.
>> 2010-03-11 11:32:37,048-0600 INFO VDL2ExecutionContext Stack dump:
>> Level 1
>> [iA = 0, iB = 0, bA = false, bB = false]
>> vdl:instanceconfig = Swift configuration []
>> vdl:operation = run
>> swift.home = /sandbox/wwj/oops/mike-swift/bin/..
>> PATH_SEPARATOR = /
>>
>>
>> 2010-03-11 11:32:37,993-0600 INFO unknown Using sites file:
>> /sandbox/wwj/oops/mike-swift/bin/../etc/sites.xml
>> 2010-03-11 11:32:37,994-0600 INFO unknown Using tc.data:
>> /sandbox/wwj/oops/mike-swift/bin/../etc/tc.data
>> 2010-03-11 11:32:38,183-0600 INFO AbstractScheduler Setting resources
>> to: {coasterpads=coasterpads, localhost=localhost, Abe=Abe,
>> QueenBee=QueenBee}
>> 2010-03-11 11:32:38,857-0600 INFO unknown Swift svn swift-r3255
>> (swift modified locally) cog-r2723
>>
>> 2010-03-11 11:32:38,858-0600 INFO unknown RUNID
>> id=tag:benc at ci.uchicago.edu,2007:swift:run:20100311-1132-4huo5g08
>> 2010-03-11 11:32:38,977-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000001
>> type string value=LoopModelResults.map dataset=unnamed SwiftScript
>> value (closed)
>> 2010-03-11 11:32:38,985-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000001
>> 2010-03-11 11:32:38,986-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000002
>> type string value=input dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,986-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000002
>> 2010-03-11 11:32:38,986-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000003
>> type string value=indir dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,986-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000003
>> 2010-03-11 11:32:38,987-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000004
>> type string value=LoopModelData.map dataset=unnamed SwiftScript value
>> (closed)
>> 2010-03-11 11:32:38,987-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000004
>> 2010-03-11 11:32:38,987-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000005
>> type string value=LoopModelIn.map dataset=unnamed SwiftScript value
>> (closed)
>> 2010-03-11 11:32:38,987-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000005
>> 2010-03-11 11:32:38,987-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000006
>> type string value=protein dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,987-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000006
>> 2010-03-11 11:32:38,988-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000007
>> type string value=4 dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,988-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000007
>> 2010-03-11 11:32:38,988-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000008
>> type string value=nSim dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,988-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000008
>> 2010-03-11 11:32:38,988-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000009
>> type string value=output dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,988-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000009
>> 2010-03-11 11:32:38,989-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000010
>> type string value=outdir dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,989-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000010
>> 2010-03-11 11:32:38,989-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000011
>> type string value=LoopModelOutArray.map dataset=unnamed SwiftScript
>> value (closed)
>> 2010-03-11 11:32:38,989-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000011
>> 2010-03-11 11:32:38,989-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000012
>> type int value=0.0 dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,990-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000012
>> 2010-03-11 11:32:38,990-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000013
>> type int value=1.0 dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:38,990-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000013
>> 2010-03-11 11:32:39,007-0600 INFO modelloops STARTCOMPOUND thread=0-1
>> name=ModelLoops
>> 2010-03-11 11:32:39,030-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000014
>> 2010-03-11 11:32:39,032-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000015
>> 2010-03-11 11:32:39,034-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000016
>> 2010-03-11 11:32:39,039-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000017
>> 2010-03-11 11:32:39,040-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000018
>> 2010-03-11 11:32:39,042-0600 INFO AbstractDataNode Adding handle
>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> type LoopModelIn with no value at dataset=modelIn (not closed)" to
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000018
>> type string with no value at dataset=swift#mapper#17007 (not closed)"
>> 2010-03-11 11:32:39,042-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> 2010-03-11 11:32:39,045-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000020
>> 2010-03-11 11:32:39,047-0600 INFO AbstractDataNode Adding handle
>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not closed)" to
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000020
>> type string with no value at dataset=swift#mapper#17009 (not closed)"
>> 2010-03-11 11:32:39,047-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> 2010-03-11 11:32:39,048-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000022
>> 2010-03-11 11:32:39,052-0600 INFO AbstractDataNode Adding handle
>> listener "modelOut.$[]/0" to "org.griphyn.vdl.mapping.RootDataNode
>> identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000022
>> type string with no value at dataset=swift#mapper#17011 (not closed)"
>> 2010-03-11 11:32:39,052-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000023
>> 2010-03-11 11:32:39,054-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000024
>> 2010-03-11 11:32:39,056-0600 INFO AbstractDataNode Adding handle
>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000025
>> type LoopModelResults with no value at dataset=modelResults (not
>> closed)" to "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000024
>> type string with no value at dataset=swift#mapper#17013 (not closed)"
>> 2010-03-11 11:32:39,056-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000025
>> 2010-03-11 11:32:39,061-0600 INFO SetFieldValue Setting
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000018
>> type string with no value at dataset=swift#mapper#17007 (not closed)
>> to LoopModelIn.map
>> 2010-03-11 11:32:39,061-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000026
>> type string value=1 dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:39,061-0600 INFO VDLFunction FUNCTION id=451000
>> name=arg
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000026
>> 2010-03-11 11:32:39,061-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451000
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000008
>> name=name
>> 2010-03-11 11:32:39,062-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451000
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000007
>> name=value
>> 2010-03-11 11:32:39,062-0600 INFO SetFieldValue Setting
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000020
>> type string with no value at dataset=swift#mapper#17009 (not closed)
>> to LoopModelData.map
>> 2010-03-11 11:32:39,062-0600 INFO AbstractDataNode Notifying listener
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not closed)"
>> about "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000020
>> type string value=LoopModelData.map dataset=swift#mapper#17009
>> (closed)"
>> 2010-03-11 11:32:39,062-0600 INFO AbstractDataNode Adding handle
>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not closed)" to
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000017
>> type string with no value at dataset=outdir (not closed)"
>> 2010-03-11 11:32:39,062-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000020
>> type string value=LoopModelData.map dataset=swift#mapper#17009
>> (closed)
>> 2010-03-11 11:32:39,062-0600 INFO SetFieldValue Setting
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000022
>> type string with no value at dataset=swift#mapper#17011 (not closed)
>> to LoopModelOutArray.map
>> 2010-03-11 11:32:39,062-0600 INFO AbstractDataNode Notifying listener
>> "modelOut.$[]/0" about "org.griphyn.vdl.mapping.RootDataNode
>> identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000022
>> type string value=LoopModelOutArray.map dataset=swift#mapper#17011
>> (closed)"
>> 2010-03-11 11:32:39,063-0600 INFO AbstractDataNode Adding handle
>> listener "modelOut.$[]/0" to "org.griphyn.vdl.mapping.RootDataNode
>> identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000014
>> type int with no value at dataset=nSim (not closed)"
>> 2010-03-11 11:32:39,063-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000022
>> type string value=LoopModelOutArray.map dataset=swift#mapper#17011
>> (closed)
>> 2010-03-11 11:32:39,063-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000027
>> type string value=T0510D1 dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:39,063-0600 INFO VDLFunction FUNCTION id=451001
>> name=arg
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000027
>> 2010-03-11 11:32:39,063-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451001
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000006
>> name=name
>> 2010-03-11 11:32:39,063-0600 INFO SetFieldValue Setting
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000015
>> type string with no value at dataset=proteinId (not closed) to T0510D1
>> 2010-03-11 11:32:39,063-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000015
>> type string value=T0510D1 dataset=proteinId (closed)
>> 2010-03-11 11:32:39,063-0600 INFO AbstractDataNode Notifying listener
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> type LoopModelIn with no value at dataset=modelIn (not closed)" about
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000018
>> type string value=LoopModelIn.map dataset=swift#mapper#17007 (closed)"
>> 2010-03-11 11:32:39,063-0600 INFO SetFieldValue Setting
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000024
>> type string with no value at dataset=swift#mapper#17013 (not closed)
>> to LoopModelResults.map
>> 2010-03-11 11:32:39,064-0600 INFO AbstractDataNode Adding handle
>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> type LoopModelIn with no value at dataset=modelIn (not closed)" to
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000016
>> type string with no value at dataset=indir (not closed)"
>> 2010-03-11 11:32:39,064-0600 INFO AbstractDataNode Notifying listener
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000025
>> type LoopModelResults with no value at dataset=modelResults (not
>> closed)" about "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000024
>> type string value=LoopModelResults.map dataset=swift#mapper#17013
>> (closed)"
>> 2010-03-11 11:32:39,064-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000018
>> type string value=LoopModelIn.map dataset=swift#mapper#17007 (closed)
>> 2010-03-11 11:32:39,064-0600 INFO AbstractDataNode Adding handle
>> listener "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000025
>> type LoopModelResults with no value at dataset=modelResults (not
>> closed)" to "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000017
>> type string with no value at dataset=outdir (not closed)"
>> 2010-03-11 11:32:39,064-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000024
>> type string value=LoopModelResults.map dataset=swift#mapper#17013
>> (closed)
>> 2010-03-11 11:32:39,064-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000028
>> type string value=input dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:39,065-0600 INFO CloseDataset Partially closing
>> T0510D1 for statement 88013
>> 2010-03-11 11:32:39,065-0600 INFO VDLFunction FUNCTION id=451002
>> name=arg
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000028
>> 2010-03-11 11:32:39,065-0600 INFO CloseDataset var is T0510D1
>> 2010-03-11 11:32:39,065-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451002
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000003
>> name=name
>> 2010-03-11 11:32:39,065-0600 INFO CloseDataset var hash is 23110255
>> 2010-03-11 11:32:39,065-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451002
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000002
>> name=value
>> 2010-03-11 11:32:39,065-0600 INFO CloseDataset variable already
>> closed - skipping partial close processing
>> 2010-03-11 11:32:39,065-0600 INFO SetFieldValue Setting
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000016
>> type string with no value at dataset=indir (not closed) to input
>> 2010-03-11 11:32:39,065-0600 INFO AbstractDataNode Notifying listener
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> type LoopModelIn with no value at dataset=modelIn (not closed)" about
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000016
>> type string value=input dataset=indir (closed)"
>> 2010-03-11 11:32:39,066-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000029
>> type string value=output dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:39,066-0600 INFO VDLFunction FUNCTION id=451003
>> name=arg
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000029
>> 2010-03-11 11:32:39,069-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451003
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000010
>> name=name
>> 2010-03-11 11:32:39,069-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451003
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000009
>> name=value
>> 2010-03-11 11:32:39,069-0600 INFO SetFieldValue Setting
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000017
>> type string with no value at dataset=outdir (not closed) to output
>> 2010-03-11 11:32:39,069-0600 INFO AbstractDataNode Notifying listener
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not closed)"
>> about "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000017
>> type string value=output dataset=outdir (closed)"
>> 2010-03-11 11:32:39,135-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000030
>> type PDB with no value at dataset=modelIn path=.pdb (closed)
>> 2010-03-11 11:32:39,137-0600 INFO AbstractDataNode Found data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> type LoopModelIn with no value at dataset=modelIn (not closed)..pdb
>> 2010-03-11 11:32:39,137-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000031
>> type Text with no value at dataset=modelIn path=.params (closed)
>> 2010-03-11 11:32:39,137-0600 INFO AbstractDataNode Found data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> type LoopModelIn with no value at dataset=modelIn (not closed)..params
>> 2010-03-11 11:32:39,138-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000032
>> type LoopRange with no value at dataset=modelIn path=.range (closed)
>> 2010-03-11 11:32:39,139-0600 INFO AbstractDataNode Found data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> type LoopModelIn with no value at dataset=modelIn (not closed)..range
>> 2010-03-11 11:32:39,139-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000019
>> type LoopModelIn with no value at dataset=modelIn (closed)
>> 2010-03-11 11:32:39,140-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000016
>> type string value=input dataset=indir (closed)
>> 2010-03-11 11:32:39,141-0600 INFO CloseDataset Partially closing
>> input for statement 88014
>> 2010-03-11 11:32:39,141-0600 INFO CloseDataset var is input
>> 2010-03-11 11:32:39,141-0600 INFO CloseDataset var hash is 22293109
>> 2010-03-11 11:32:39,141-0600 INFO CloseDataset variable already
>> closed - skipping partial close processing
>> 2010-03-11 11:32:39,146-0600 INFO loopprepare PROCEDURE line=112
>> thread=0-1-8 name=loopPrepare
>> 2010-03-11 11:32:39,146-0600 INFO strtoi STARTCOMPOUND thread=0-1-0
>> name=strtoi
>> 2010-03-11 11:32:39,147-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..fasta
>> 2010-03-11 11:32:39,147-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..pdb
>> 2010-03-11 11:32:39,147-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..native
>> 2010-03-11 11:32:39,147-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..index
>> 2010-03-11 11:32:39,147-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..params
>> 2010-03-11 11:32:39,148-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..range
>> 2010-03-11 11:32:39,148-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..rama
>> 2010-03-11 11:32:39,148-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..map
>> 2010-03-11 11:32:39,148-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not
>> closed)..secseq
>> 2010-03-11 11:32:39,148-0600 INFO AbstractDataNode Notifying listener
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000025
>> type LoopModelResults with no value at dataset=modelResults (not
>> closed)" about "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000017
>> type string value=output dataset=outdir (closed)"
>> 2010-03-11 11:32:39,148-0600 INFO loopmodelanalysis PROCEDURE
>> line=122 thread=0-1-10 name=loopModelAnalysis
>> 2010-03-11 11:32:39,149-0600 INFO doloopround STARTCOMPOUND
>> thread=0-1-9 name=doLoopRound
>> 2010-03-11 11:32:39,160-0600 INFO New NEW
>> id=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> 2010-03-11 11:32:39,168-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000025
>> type LoopModelResults with no value at dataset=modelResults (not
>> closed)..pwPlot
>> 2010-03-11 11:32:39,168-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000025
>> type LoopModelResults with no value at dataset=modelResults (not
>> closed)..best
>> 2010-03-11 11:32:39,168-0600 INFO AbstractDataNode Adding handle
>> listener "F/org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000014
>> type int with no value at dataset=nSim (not closed)" to
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000014
>> type int with no value at dataset=nSim (not closed)"
>> 2010-03-11 11:32:39,168-0600 INFO AbstractDataNode Found mapped data
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000025
>> type LoopModelResults with no value at dataset=modelResults (not
>> closed)..ligationPlot
>> 2010-03-11 11:32:39,168-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000017
>> type string value=output dataset=outdir (closed)
>> 2010-03-11 11:32:39,169-0600 INFO AbstractDataNode Adding handle
>> listener "F/modelOut.$[]/0" to
>> "org.griphyn.vdl.mapping.RootArrayDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000023
>> type LoopModelOut[] with no value at dataset=modelOut (not closed)"
>> 2010-03-11 11:32:39,169-0600 INFO CloseDataset Partially closing
>> output for statement 88015
>> 2010-03-11 11:32:39,169-0600 INFO CloseDataset var is output
>> 2010-03-11 11:32:39,169-0600 INFO CloseDataset var hash is 22608339
>> 2010-03-11 11:32:39,169-0600 INFO CloseDataset variable already
>> closed - skipping partial close processing
>> 2010-03-11 11:32:39,170-0600 INFO strtoi INTERNALPROC_START
>> thread=0-1-0-1 name=readData
>> 2010-03-11 11:32:39,172-0600 INFO AbstractDataNode Adding handle
>> listener "F/org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> type file with no value at dataset=f (not closed)" to
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> type file with no value at dataset=f (not closed)"
>> 2010-03-11 11:32:39,173-0600 INFO echos PROCEDURE line=68
>> thread=0-1-0-0 name=echos
>> 2010-03-11 11:32:39,181-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000046
>> type string value=input/T0510D1.pdb dataset=unnamed SwiftScript value
>> (closed)
>> 2010-03-11 11:32:39,181-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451004
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000030
>> name=input
>> 2010-03-11 11:32:39,182-0600 INFO VDLFunction FUNCTION id=451004
>> name=filename
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000046
>> 2010-03-11 11:32:39,182-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000047
>> type string value=output/data//T0510D1.pdb dataset=unnamed SwiftScript
>> value (closed)
>> 2010-03-11 11:32:39,182-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451005
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000034
>> name=input
>> 2010-03-11 11:32:39,182-0600 INFO VDLFunction FUNCTION id=451005
>> name=filename
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000047
>> 2010-03-11 11:32:39,183-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000048
>> type string
>> value=_concurrent/f-19e32663-bd41-4000-a822-2d3f19dfccf1-1-0
>> dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:39,183-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451006
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> name=input
>> 2010-03-11 11:32:39,183-0600 INFO VDLFunction FUNCTION id=451006
>> name=filename
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000048
>> 2010-03-11 11:32:39,188-0600 INFO vdl:execute START thread=0-1-0-0
>> tr=echo
>> 2010-03-11 11:32:39,188-0600 INFO vdl:execute START thread=0-1-8
>> tr=PrepLoop
>> 2010-03-11 11:32:39,209-0600 INFO WeightedHostScoreScheduler Sorted:
>> [localhost:10,000.000(99.854):0/3 overload: 0]
>> 2010-03-11 11:32:39,209-0600 INFO WeightedHostScoreScheduler
>> CONTACT_SELECTED host=localhost, score=99.854
>> 2010-03-11 11:32:39,211-0600 INFO WeightedHostScoreScheduler Sorted:
>> [localhost:10,000.000(99.854):1/3 overload: 0]
>> 2010-03-11 11:32:39,211-0600 INFO WeightedHostScoreScheduler
>> CONTACT_SELECTED host=localhost, score=99.854
>> 2010-03-11 11:32:39,216-0600 INFO GlobalSubmitQueue No global submit
>> throttle set. Using default (100)
>> 2010-03-11 11:32:39,232-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759207) setting status to Submitting
>> 2010-03-11 11:32:39,248-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759207) setting status to Submitted
>> 2010-03-11 11:32:39,248-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759207) setting status to Active
>> 2010-03-11 11:32:39,248-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759207) setting status to Completed
>> 2010-03-11 11:32:39,249-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1268328759207)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 1M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,251-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759210) setting status to Submitting
>> 2010-03-11 11:32:39,251-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759210) setting status to Submitted
>> 2010-03-11 11:32:39,251-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759210) setting status to Active
>> 2010-03-11 11:32:39,251-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759210) setting status to Completed
>> 2010-03-11 11:32:39,252-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1268328759210)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 1M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,254-0600 INFO vdl:initshareddir START
>> host=localhost - Initializing shared directory
>> 2010-03-11 11:32:39,259-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759212) setting status to Submitting
>> 2010-03-11 11:32:39,259-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759212) setting status to Submitted
>> 2010-03-11 11:32:39,259-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759212) setting status to Active
>> 2010-03-11 11:32:39,260-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759212) setting status to Completed
>> 2010-03-11 11:32:39,260-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1268328759212)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,277-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759215) setting status to Submitting
>> 2010-03-11 11:32:39,278-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759215) setting status to Submitted
>> 2010-03-11 11:32:39,278-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759215) setting status to Active
>> 2010-03-11 11:32:39,279-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759215) setting status to Completed
>> 2010-03-11 11:32:39,279-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-1268328759215)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 1M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,281-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759218) setting status to Submitting
>> 2010-03-11 11:32:39,281-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759218) setting status to Submitted
>> 2010-03-11 11:32:39,281-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759218) setting status to Active
>> 2010-03-11 11:32:39,282-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759218) setting status to Completed
>> 2010-03-11 11:32:39,282-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-1268328759218)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 1M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,283-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759221) setting status to Submitting
>> 2010-03-11 11:32:39,283-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759221) setting status to Submitted
>> 2010-03-11 11:32:39,283-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759221) setting status to Active
>> 2010-03-11 11:32:39,283-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759221) setting status to Completed
>> 2010-03-11 11:32:39,283-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1268328759221)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 1M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,285-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759223) setting status to Submitting
>> 2010-03-11 11:32:39,285-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759223) setting status to Submitted
>> 2010-03-11 11:32:39,285-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759223) setting status to Active
>> 2010-03-11 11:32:39,285-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759223) setting status to Completed
>> 2010-03-11 11:32:39,286-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1268328759223)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 1M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,290-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759225) setting status to Submitting
>> 2010-03-11 11:32:39,290-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759225) setting status to Submitted
>> 2010-03-11 11:32:39,290-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759225) setting status to Active
>> 2010-03-11 11:32:39,290-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759225) setting status to Completed
>> 2010-03-11 11:32:39,291-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1268328759225)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 1M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,292-0600 INFO vdl:initshareddir END
>> host=localhost - Done initializing shared directory
>> 2010-03-11 11:32:39,293-0600 DEBUG vdl:execute2 THREAD_ASSOCIATION
>> jobid=echo-mqsbkyoj thread=0-1-0-0-1 host=localhost
>> replicationGroup=kqsbkyoj
>> 2010-03-11 11:32:39,294-0600 DEBUG vdl:execute2 THREAD_ASSOCIATION
>> jobid=PrepLoop-nqsbkyoj thread=0-1-8-1 host=localhost
>> replicationGroup=lqsbkyoj
>> 2010-03-11 11:32:39,302-0600 INFO vdl:createdirset START
>> jobid=echo-mqsbkyoj host=localhost - Initializing directory structure
>> 2010-03-11 11:32:39,303-0600 INFO vdl:createdirset START
>> jobid=PrepLoop-nqsbkyoj host=localhost - Initializing directory
>> structure
>> 2010-03-11 11:32:39,304-0600 INFO vdl:createdirs START
>> path=_concurrent dir=psim.loops-20100311-1132-4huo5g08/shared -
>> Creating directory structure
>> 2010-03-11 11:32:39,304-0600 INFO vdl:createdirs START path=input
>> dir=psim.loops-20100311-1132-4huo5g08/shared - Creating directory
>> structure
>> 2010-03-11 11:32:39,305-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759227) setting status to Submitting
>> 2010-03-11 11:32:39,305-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759227) setting status to Submitted
>> 2010-03-11 11:32:39,305-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759227) setting status to Active
>> 2010-03-11 11:32:39,305-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759227) setting status to Completed
>> 2010-03-11 11:32:39,305-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759229) setting status to Submitting
>> 2010-03-11 11:32:39,305-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759229) setting status to Submitted
>> 2010-03-11 11:32:39,305-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759229) setting status to Active
>> 2010-03-11 11:32:39,306-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759229) setting status to Completed
>> 2010-03-11 11:32:39,306-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1268328759229)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,307-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1268328759227)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,307-0600 INFO vdl:createdirset END
>> jobid=echo-mqsbkyoj - Done initializing directory structure
>> 2010-03-11 11:32:39,307-0600 INFO vdl:createdirs START
>> path=output/data/ dir=psim.loops-20100311-1132-4huo5g08/shared -
>> Creating directory structure
>> 2010-03-11 11:32:39,311-0600 INFO vdl:dostagein START
>> jobid=echo-mqsbkyoj - Staging in files
>> 2010-03-11 11:32:39,311-0600 INFO vdl:dostagein END
>> jobid=echo-mqsbkyoj - Staging in finished
>> 2010-03-11 11:32:39,314-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759231) setting status to Submitting
>> 2010-03-11 11:32:39,314-0600 DEBUG vdl:execute2 JOB_START
>> jobid=echo-mqsbkyoj tr=echo arguments=[1]
>> tmpdir=psim.loops-20100311-1132-4huo5g08/jobs/m/echo-mqsbkyoj
>> host=localhost
>> 2010-03-11 11:32:39,314-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759231) setting status to Submitted
>> 2010-03-11 11:32:39,315-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759231) setting status to Active
>> 2010-03-11 11:32:39,316-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759231) setting status to Completed
>> 2010-03-11 11:32:39,317-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1268328759231)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 1M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,318-0600 INFO vdl:createdirs START path=
>> dir=psim.loops-20100311-1132-4huo5g08/shared - Creating directory
>> structure
>> 2010-03-11 11:32:39,318-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759233) setting status to Submitting
>> 2010-03-11 11:32:39,318-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759233) setting status to Submitted
>> 2010-03-11 11:32:39,318-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759233) setting status to Active
>> 2010-03-11 11:32:39,319-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759233) setting status to Completed
>> 2010-03-11 11:32:39,319-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1268328759233)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,321-0600 INFO vdl:createdirset END
>> jobid=PrepLoop-nqsbkyoj - Done initializing directory structure
>> 2010-03-11 11:32:39,322-0600 INFO vdl:dostagein START
>> jobid=PrepLoop-nqsbkyoj - Staging in files
>> 2010-03-11 11:32:39,326-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759236) setting status to Submitting
>> 2010-03-11 11:32:39,326-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759236) setting status to Submitted
>> 2010-03-11 11:32:39,326-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759236) setting status to Active
>> 2010-03-11 11:32:39,328-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759237) setting status to Submitting
>> 2010-03-11 11:32:39,329-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759237) setting status to Submitted
>> 2010-03-11 11:32:39,329-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759237) setting status to Active
>> 2010-03-11 11:32:39,329-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759237) setting status to Completed
>> 2010-03-11 11:32:39,330-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1-1268328759237)
>> Completed. Waiting: 0, Running: 2. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,331-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759236) setting status to Completed
>> 2010-03-11 11:32:39,331-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-3-1268328759236)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,332-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759239) setting status to Submitting
>> 2010-03-11 11:32:39,332-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759239) setting status to Submitted
>> 2010-03-11 11:32:39,332-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759239) setting status to Active
>> 2010-03-11 11:32:39,333-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759239) setting status to Completed
>> 2010-03-11 11:32:39,335-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-2-1268328759239)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,342-0600 INFO Execute jobid=echo-mqsbkyoj
>> task=Task(type=JOB_SUBMISSION, identity=urn:0-1-0-0-1-1268328759242)
>> 2010-03-11 11:32:39,343-0600 DEBUG vdl:dostagein FILE_STAGE_IN_START
>> file=file://localhost/input/T0510D1.pdb srchost=localhost srcdir=input
>> srcname=T0510D1.pdb desthost=localhost
>> destdir=psim.loops-20100311-1132-4huo5g08/shared/input provider=file
>> 2010-03-11 11:32:39,344-0600 DEBUG vdl:dostagein FILE_STAGE_IN_START
>> file=file://localhost/input/T0510D1.range srchost=localhost
>> srcdir=input srcname=T0510D1.range desthost=localhost
>> destdir=psim.loops-20100311-1132-4huo5g08/shared/input provider=file
>> 2010-03-11 11:32:39,345-0600 DEBUG vdl:dostagein FILE_STAGE_IN_START
>> file=file://localhost/input/T0510D1.params srchost=localhost
>> srcdir=input srcname=T0510D1.params desthost=localhost
>> destdir=psim.loops-20100311-1132-4huo5g08/shared/input provider=file
>> 2010-03-11 11:32:39,346-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-2-1268328759246) setting status to Submitting
>> 2010-03-11 11:32:39,346-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-2-1268328759246) setting status to Submitted
>> 2010-03-11 11:32:39,346-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-3-1268328759245) setting status to Submitting
>> 2010-03-11 11:32:39,346-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-3-1268328759245) setting status to Submitted
>> 2010-03-11 11:32:39,346-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-2-1268328759246) setting status to Active
>> 2010-03-11 11:32:39,346-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-3-1268328759245) setting status to Active
>> 2010-03-11 11:32:39,347-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1-1268328759248) setting status to Submitting
>> 2010-03-11 11:32:39,347-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1-1268328759248) setting status to Submitted
>> 2010-03-11 11:32:39,348-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1-1268328759248) setting status to Active
>> 2010-03-11 11:32:39,349-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-3-1268328759245) setting status to Completed
>> 2010-03-11 11:32:39,349-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-3-1268328759245)
>> Completed. Waiting: 0, Running: 3. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,349-0600 DEBUG vdl:dostagein FILE_STAGE_IN_END
>> file=file://localhost/input/T0510D1.pdb srchost=localhost srcdir=input
>> srcname=T0510D1.pdb desthost=localhost
>> destdir=psim.loops-20100311-1132-4huo5g08/shared/input provider=file
>> 2010-03-11 11:32:39,350-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION,
>> identity=urn:0-1-0-0-1-1268328759242) setting status to Submitting
>> 2010-03-11 11:32:39,350-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1-1268328759248) setting status to Completed
>> 2010-03-11 11:32:39,351-0600 INFO JobSubmissionTaskHandler Submitting
>> task Task(type=JOB_SUBMISSION, identity=urn:0-1-0-0-1-1268328759242)
>> 2010-03-11 11:32:39,351-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-1-1268328759248)
>> Completed. Waiting: 0, Running: 2. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,351-0600 INFO JobSubmissionTaskHandler Submitting
>> single job
>> 2010-03-11 11:32:39,351-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION,
>> identity=urn:0-1-0-0-1-1268328759242) setting status to Submitted
>> 2010-03-11 11:32:39,351-0600 DEBUG vdl:dostagein FILE_STAGE_IN_END
>> file=file://localhost/input/T0510D1.params srchost=localhost
>> srcdir=input srcname=T0510D1.params desthost=localhost
>> destdir=psim.loops-20100311-1132-4huo5g08/shared/input provider=file
>> 2010-03-11 11:32:39,356-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION,
>> identity=urn:0-1-0-0-1-1268328759242) setting status to Active
>> 2010-03-11 11:32:39,360-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-2-1268328759246) setting status to Completed
>> 2010-03-11 11:32:39,361-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-2-1268328759246)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,361-0600 DEBUG vdl:dostagein FILE_STAGE_IN_END
>> file=file://localhost/input/T0510D1.range srchost=localhost
>> srcdir=input srcname=T0510D1.range desthost=localhost
>> destdir=psim.loops-20100311-1132-4huo5g08/shared/input provider=file
>> 2010-03-11 11:32:39,361-0600 INFO vdl:dostagein END
>> jobid=PrepLoop-nqsbkyoj - Staging in finished
>> 2010-03-11 11:32:39,362-0600 DEBUG vdl:execute2 JOB_START
>> jobid=PrepLoop-nqsbkyoj tr=PrepLoop arguments=[input/T0510D1.pdb,
>> output/data//T0510D1.pdb]
>> tmpdir=psim.loops-20100311-1132-4huo5g08/jobs/n/PrepLoop-nqsbkyoj
>> host=localhost
>> 2010-03-11 11:32:39,376-0600 INFO Execute jobid=PrepLoop-nqsbkyoj
>> task=Task(type=JOB_SUBMISSION, identity=urn:0-1-8-1-1268328759253)
>> 2010-03-11 11:32:39,377-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION,
>> identity=urn:0-1-8-1-1268328759253) setting status to Submitting
>> 2010-03-11 11:32:39,377-0600 INFO JobSubmissionTaskHandler Submitting
>> task Task(type=JOB_SUBMISSION, identity=urn:0-1-8-1-1268328759253)
>> 2010-03-11 11:32:39,377-0600 INFO JobSubmissionTaskHandler Submitting
>> single job
>> 2010-03-11 11:32:39,377-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION,
>> identity=urn:0-1-8-1-1268328759253) setting status to Submitted
>> 2010-03-11 11:32:39,381-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION,
>> identity=urn:0-1-8-1-1268328759253) setting status to Active
>> 2010-03-11 11:32:39,494-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION,
>> identity=urn:0-1-0-0-1-1268328759242) setting status to Completed
>> 2010-03-11 11:32:39,494-0600 INFO LateBindingScheduler
>> Task(type=JOB_SUBMISSION, identity=urn:0-1-0-0-1-1268328759242)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,497-0600 DEBUG vdl:checkjobstatus START
>> jobid=echo-mqsbkyoj
>> 2010-03-11 11:32:39,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759255) setting status to Submitting
>> 2010-03-11 11:32:39,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759255) setting status to Submitted
>> 2010-03-11 11:32:39,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759255) setting status to Active
>> 2010-03-11 11:32:39,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1268328759255) setting status to Completed
>> 2010-03-11 11:32:39,498-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1268328759255)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,499-0600 INFO vdl:checkjobstatus SUCCESS
>> jobid=echo-mqsbkyoj - Success file found
>> 2010-03-11 11:32:39,499-0600 DEBUG vdl:execute2 STAGING_OUT
>> jobid=echo-mqsbkyoj
>> 2010-03-11 11:32:39,500-0600 INFO vdl:dostageout START
>> jobid=echo-mqsbkyoj - Staging out files
>> 2010-03-11 11:32:39,505-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=f-19e32663-bd41-4000-a822-2d3f19dfccf1-1-0
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/_concurrent
>> srchost=localhost destdir=_concurrent desthost=localhost provider=file
>> 2010-03-11 11:32:39,506-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1-1268328759257) setting status to Submitting
>> 2010-03-11 11:32:39,506-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1-1268328759257) setting status to Submitted
>> 2010-03-11 11:32:39,506-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1-1268328759257) setting status to Active
>> 2010-03-11 11:32:39,507-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1-1268328759257) setting status to Completed
>> 2010-03-11 11:32:39,507-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1-1268328759257)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,508-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-0-0-1-1-1268328759259) setting status to Submitting
>> 2010-03-11 11:32:39,508-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-0-0-1-1-1268328759259) setting status to Submitted
>> 2010-03-11 11:32:39,508-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-0-0-1-1-1268328759259) setting status to Active
>> 2010-03-11 11:32:39,509-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-0-0-1-1-1268328759259) setting status to Completed
>> 2010-03-11 11:32:39,509-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-0-0-1-1-1268328759259)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,510-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=f-19e32663-bd41-4000-a822-2d3f19dfccf1-1-0
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/_concurrent
>> srchost=localhost destdir=_concurrent desthost=localhost provider=file
>> 2010-03-11 11:32:39,510-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1-1268328759262) setting status to Submitting
>> 2010-03-11 11:32:39,511-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1-1268328759262) setting status to Submitted
>> 2010-03-11 11:32:39,511-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1-1268328759262) setting status to Active
>> 2010-03-11 11:32:39,511-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-0-0-1-1-1268328759262) setting status to Completed
>> 2010-03-11 11:32:39,511-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-0-0-1-1-1268328759262)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,514-0600 INFO vdl:dostageout END
>> jobid=echo-mqsbkyoj - Staging out finished
>> 2010-03-11 11:32:39,518-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-0-0-1-1268328759264) setting status to Submitting
>> 2010-03-11 11:32:39,518-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-0-0-1-1268328759264) setting status to Submitted
>> 2010-03-11 11:32:39,518-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-0-0-1-1268328759264) setting status to Active
>> 2010-03-11 11:32:39,519-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-0-0-1-1268328759264) setting status to Completed
>> 2010-03-11 11:32:39,519-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-0-0-1-1268328759264)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:39,520-0600 DEBUG vdl:execute2 JOB_END
>> jobid=echo-mqsbkyoj
>> 2010-03-11 11:32:39,522-0600 INFO vdl:execute END_SUCCESS
>> thread=0-1-0-0 tr=echo
>> 2010-03-11 11:32:39,676-0600 INFO CloseDataset Closing
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> type file with no value at dataset=f (not closed)
>> 2010-03-11 11:32:39,676-0600 INFO AbstractDataNode Notifying listener
>> "F/org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> type file with no value at dataset=f (closed)" about
>> "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> type file with no value at dataset=f (closed)"
>> 2010-03-11 11:32:39,677-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> type file with no value at dataset=f (closed)
>> 2010-03-11 11:32:39,677-0600 INFO echos PROCEDURE_END line=68
>> 2010-03-11 11:32:39,681-0600 INFO AbstractDataNode Notifying listener
>> "modelOut.$[]/0" about "org.griphyn.vdl.mapping.RootDataNode
>> identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000014
>> type int value=1.0 dataset=nSim (closed)"
>> 2010-03-11 11:32:39,681-0600 INFO CloseDataset Partially closing
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> type file with no value at dataset=f (closed) for statement 88004
>> 2010-03-11 11:32:39,681-0600 INFO CloseDataset var is
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000042
>> type file with no value at dataset=f (closed)
>> 2010-03-11 11:32:39,681-0600 INFO CloseDataset var hash is 7971559
>> 2010-03-11 11:32:39,681-0600 INFO CloseDataset variable already
>> closed - skipping partial close processing
>> 2010-03-11 11:32:39,739-0600 INFO AbstractDataNode Found mapped data
>> modelOut.$[]/1.[0].cfg
>> 2010-03-11 11:32:39,739-0600 INFO AbstractDataNode Found mapped data
>> modelOut.$[]/1.[0].pdt
>> 2010-03-11 11:32:39,739-0600 INFO AbstractDataNode Found mapped data
>> modelOut.$[]/1.[0].log
>> 2010-03-11 11:32:39,739-0600 INFO AbstractDataNode Found mapped data
>> modelOut.$[]/1.[0].pdb
>> 2010-03-11 11:32:39,739-0600 INFO AbstractDataNode Notifying listener
>> "F/modelOut.$[]/1" about "org.griphyn.vdl.mapping.RootArrayDataNode
>> identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000023
>> type LoopModelOut[] with no value at dataset=modelOut (closed)"
>> 2010-03-11 11:32:39,740-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootArrayDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000023
>> type LoopModelOut[] with no value at dataset=modelOut (closed)
>> 2010-03-11 11:32:39,740-0600 INFO AbstractDataNode Notifying listener
>> "F/1" about "org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000014
>> type int value=1.0 dataset=nSim (closed)"
>> 2010-03-11 11:32:39,740-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000014
>> type int value=1.0 dataset=nSim (closed)
>> 2010-03-11 11:32:39,741-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000054
>> type int value=0.0 dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:39,741-0600 INFO strtoi INTERNALPROC_END
>> thread=0-1-0-1
>> 2010-03-11 11:32:39,741-0600 INFO CloseDataset Closing 1
>> 2010-03-11 11:32:39,742-0600 INFO strtoi ENDCOMPOUND thread=0-1-0
>> 2010-03-11 11:32:39,742-0600 INFO AbstractDataNode Adding handle
>> listener "F/org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000052
>> type ModelLog with no value at dataset=modelOut path=[0].log (not
>> closed)" to "org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000052
>> type ModelLog with no value at dataset=modelOut path=[0].log (not
>> closed)"
>> 2010-03-11 11:32:39,749-0600 INFO CloseDataset Partially closing 1
>> for statement 88012
>> 2010-03-11 11:32:39,749-0600 INFO CloseDataset var is 1
>> 2010-03-11 11:32:39,749-0600 INFO CloseDataset var hash is 29094346
>> 2010-03-11 11:32:39,749-0600 INFO CloseDataset variable already
>> closed - skipping partial close processing
>> 2010-03-11 11:32:39,752-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000056
>> type int value=0.0 dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:39,752-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.karajan.lib.Range$1 identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000055
>> type int[] with no value at dataset=unnamed SwiftScript value (closed)
>> 2010-03-11 11:32:39,753-0600 INFO doloopround FOREACH_IT_START
>> line=130 thread=0-1-9-1-1
>> 2010-03-11 11:32:39,754-0600 INFO doloopround SCOPE thread=0-1-9-1-1
>> 2010-03-11 11:32:39,756-0600 INFO loopmodel PROCEDURE line=117
>> thread=0-1-9-1-1-1 name=loopModel
>> 2010-03-11 11:32:39,757-0600 INFO AbstractDataNode Adding handle
>> listener "F/org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000036
>> type RamaIndex with no value at dataset=modelData path=.index (not
>> closed)" to "org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000036
>> type RamaIndex with no value at dataset=modelData path=.index (not
>> closed)"
>> 2010-03-11 11:32:51,421-0600 DEBUG TaskImpl Task(type=JOB_SUBMISSION,
>> identity=urn:0-1-8-1-1268328759253) setting status to Completed
>> 2010-03-11 11:32:51,421-0600 INFO LateBindingScheduler
>> Task(type=JOB_SUBMISSION, identity=urn:0-1-8-1-1268328759253)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,422-0600 DEBUG vdl:checkjobstatus START
>> jobid=PrepLoop-nqsbkyoj
>> 2010-03-11 11:32:51,423-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759267) setting status to Submitting
>> 2010-03-11 11:32:51,424-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759267) setting status to Submitted
>> 2010-03-11 11:32:51,424-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759267) setting status to Active
>> 2010-03-11 11:32:51,425-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1268328759267) setting status to Completed
>> 2010-03-11 11:32:51,425-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1268328759267)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,425-0600 INFO vdl:checkjobstatus SUCCESS
>> jobid=PrepLoop-nqsbkyoj - Success file found
>> 2010-03-11 11:32:51,425-0600 DEBUG vdl:execute2 STAGING_OUT
>> jobid=PrepLoop-nqsbkyoj
>> 2010-03-11 11:32:51,426-0600 INFO vdl:dostageout START
>> jobid=PrepLoop-nqsbkyoj - Staging out files
>> 2010-03-11 11:32:51,438-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=T0510D1.secseq
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,438-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=T0510D1.rama_map
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,438-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=T0510D1.rama
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,438-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=void srcdir=psim.loops-20100311-1132-4huo5g08/shared/
>> srchost=localhost destdir= desthost=localhost provider=file
>> 2010-03-11 11:32:51,438-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=T0510D1.range
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,438-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=T0510D1.pdb
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,438-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=T0510D1.rama_index
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,439-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=T0510D1.fasta
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,439-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_START
>> srcname=T0510D1.params
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,440-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759269) setting status to Submitting
>> 2010-03-11 11:32:51,447-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759269) setting status to Submitted
>> 2010-03-11 11:32:51,447-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759269) setting status to Active
>> 2010-03-11 11:32:51,447-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759269) setting status to Completed
>> 2010-03-11 11:32:51,447-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-2-1268328759269)
>> Completed. Waiting: 1, Running: 7. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,440-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-5-1268328759272) setting status to Submitting
>> 2010-03-11 11:32:51,448-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-5-1268328759272) setting status to Submitted
>> 2010-03-11 11:32:51,448-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-5-1268328759272) setting status to Active
>> 2010-03-11 11:32:51,448-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-5-1268328759272) setting status to Completed
>> 2010-03-11 11:32:51,448-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-5-1268328759272)
>> Completed. Waiting: 2, Running: 6. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,448-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-7-1268328759273) setting status to Submitting
>> 2010-03-11 11:32:51,450-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-7-1268328759273) setting status to Submitted
>> 2010-03-11 11:32:51,450-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-7-1268328759273) setting status to Active
>> 2010-03-11 11:32:51,451-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-7-1268328759273) setting status to Completed
>> 2010-03-11 11:32:51,451-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-7-1268328759273)
>> Completed. Waiting: 0, Running: 8. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,449-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-4-1268328759276) setting status to Submitting
>> 2010-03-11 11:32:51,451-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-4-1268328759276) setting status to Submitted
>> 2010-03-11 11:32:51,451-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-4-1268328759276) setting status to Active
>> 2010-03-11 11:32:51,452-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-4-1268328759276) setting status to Completed
>> 2010-03-11 11:32:51,452-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-4-1268328759276)
>> Completed. Waiting: 0, Running: 8. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,451-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-6-1268328759277) setting status to Submitting
>> 2010-03-11 11:32:51,453-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-6-1268328759277) setting status to Submitted
>> 2010-03-11 11:32:51,453-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-6-1268328759277) setting status to Active
>> 2010-03-11 11:32:51,453-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-6-1268328759277) setting status to Completed
>> 2010-03-11 11:32:51,453-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-6-1268328759277)
>> Completed. Waiting: 1, Running: 7. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,453-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-9-1268328759279) setting status to Submitting
>> 2010-03-11 11:32:51,453-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-9-1268328759279) setting status to Submitted
>> 2010-03-11 11:32:51,453-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-9-1268328759279) setting status to Active
>> 2010-03-11 11:32:51,453-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-9-1268328759279) setting status to Completed
>> 2010-03-11 11:32:51,454-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-9-1268328759279)
>> Completed. Waiting: 1, Running: 7. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,454-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759281) setting status to Submitting
>> 2010-03-11 11:32:51,454-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759281) setting status to Submitted
>> 2010-03-11 11:32:51,454-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759281) setting status to Active
>> 2010-03-11 11:32:51,454-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759281) setting status to Completed
>> 2010-03-11 11:32:51,454-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1-1268328759281)
>> Completed. Waiting: 2, Running: 6. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,455-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-8-1268328759283) setting status to Submitting
>> 2010-03-11 11:32:51,455-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-8-1268328759283) setting status to Submitted
>> 2010-03-11 11:32:51,455-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-8-1268328759283) setting status to Active
>> 2010-03-11 11:32:51,455-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-8-1268328759283) setting status to Completed
>> 2010-03-11 11:32:51,455-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-8-1268328759283)
>> Completed. Waiting: 3, Running: 5. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,455-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759285) setting status to Submitting
>> 2010-03-11 11:32:51,455-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759285) setting status to Submitted
>> 2010-03-11 11:32:51,455-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759285) setting status to Active
>> 2010-03-11 11:32:51,456-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-2-1268328759287) setting status to Submitting
>> 2010-03-11 11:32:51,456-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759285) setting status to Completed
>> 2010-03-11 11:32:51,456-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-2-1268328759287) setting status to Submitted
>> 2010-03-11 11:32:51,456-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-3-1268328759285)
>> Completed. Waiting: 4, Running: 4. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,457-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-2-1268328759287) setting status to Active
>> 2010-03-11 11:32:51,457-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-7-1268328759291) setting status to Submitting
>> 2010-03-11 11:32:51,457-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-7-1268328759291) setting status to Submitted
>> 2010-03-11 11:32:51,457-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-4-1268328759293) setting status to Submitting
>> 2010-03-11 11:32:51,457-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-7-1268328759291) setting status to Active
>> 2010-03-11 11:32:51,458-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-2-1268328759287) setting status to Completed
>> 2010-03-11 11:32:51,458-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-2-1268328759287)
>> Completed. Waiting: 5, Running: 3. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,458-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-5-1268328759289) setting status to Submitting
>> 2010-03-11 11:32:51,458-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-5-1268328759289) setting status to Submitted
>> 2010-03-11 11:32:51,458-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=T0510D1.secseq
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,459-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-6-1268328759295) setting status to Submitting
>> 2010-03-11 11:32:51,459-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-6-1268328759295) setting status to Submitted
>> 2010-03-11 11:32:51,459-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-6-1268328759295) setting status to Active
>> 2010-03-11 11:32:51,460-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-6-1268328759295) setting status to Completed
>> 2010-03-11 11:32:51,460-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-6-1268328759295)
>> Completed. Waiting: 4, Running: 4. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,457-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-4-1268328759293) setting status to Submitted
>> 2010-03-11 11:32:51,464-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-9-1268328759297) setting status to Submitting
>> 2010-03-11 11:32:51,464-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-9-1268328759297) setting status to Submitted
>> 2010-03-11 11:32:51,464-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-9-1268328759297) setting status to Active
>> 2010-03-11 11:32:51,465-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-5-1268328759289) setting status to Active
>> 2010-03-11 11:32:51,465-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759307) setting status to Submitting
>> 2010-03-11 11:32:51,465-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759307) setting status to Submitted
>> 2010-03-11 11:32:51,465-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759307) setting status to Active
>> 2010-03-11 11:32:51,466-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-2-1268328759307) setting status to Completed
>> 2010-03-11 11:32:51,466-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-2-1268328759307)
>> Completed. Waiting: 3, Running: 4. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,469-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-7-1268328759291) setting status to Completed
>> 2010-03-11 11:32:51,470-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-9-1268328759297) setting status to Completed
>> 2010-03-11 11:32:51,470-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-7-1268328759291)
>> Completed. Waiting: 3, Running: 3. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,470-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1-1268328759299) setting status to Submitting
>> 2010-03-11 11:32:51,470-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1-1268328759299) setting status to Submitted
>> 2010-03-11 11:32:51,470-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=T0510D1.rama
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,471-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=T0510D1.range
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,471-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-7-1268328759312) setting status to Submitting
>> 2010-03-11 11:32:51,471-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-6-1268328759314) setting status to Submitting
>> 2010-03-11 11:32:51,471-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-6-1268328759314) setting status to Submitted
>> 2010-03-11 11:32:51,471-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-6-1268328759314) setting status to Active
>> 2010-03-11 11:32:51,472-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-6-1268328759314) setting status to Completed
>> 2010-03-11 11:32:51,472-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-6-1268328759314)
>> Completed. Waiting: 2, Running: 5. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,472-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-4-1268328759293) setting status to Active
>> 2010-03-11 11:32:51,472-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-9-1268328759297)
>> Completed. Waiting: 4, Running: 4. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,473-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-8-1268328759301) setting status to Submitting
>> 2010-03-11 11:32:51,471-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-7-1268328759312) setting status to Submitted
>> 2010-03-11 11:32:51,473-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-4-1268328759293) setting status to Completed
>> 2010-03-11 11:32:51,473-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1-1268328759299) setting status to Active
>> 2010-03-11 11:32:51,473-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-8-1268328759301) setting status to Submitted
>> 2010-03-11 11:32:51,474-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-8-1268328759301) setting status to Active
>> 2010-03-11 11:32:51,474-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-8-1268328759301) setting status to Completed
>> 2010-03-11 11:32:51,475-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-8-1268328759301)
>> Completed. Waiting: 1, Running: 4. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,475-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-3-1268328759303) setting status to Submitting
>> 2010-03-11 11:32:51,475-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-3-1268328759303) setting status to Submitted
>> 2010-03-11 11:32:51,475-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=T0510D1.fasta
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,476-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-3-1268328759303) setting status to Active
>> 2010-03-11 11:32:51,477-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-3-1268328759303) setting status to Completed
>> 2010-03-11 11:32:51,477-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-3-1268328759303)
>> Completed. Waiting: 0, Running: 5. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,477-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=T0510D1.params
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,478-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=T0510D1.pdb
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,480-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-8-1268328759319) setting status to Submitting
>> 2010-03-11 11:32:51,480-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-8-1268328759319) setting status to Submitted
>> 2010-03-11 11:32:51,481-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-8-1268328759319) setting status to Active
>> 2010-03-11 11:32:51,481-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-8-1268328759319) setting status to Completed
>> 2010-03-11 11:32:51,481-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-8-1268328759319)
>> Completed. Waiting: 0, Running: 6. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,495-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-5-1268328759289) setting status to Completed
>> 2010-03-11 11:32:51,496-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-5-1268328759289)
>> Completed. Waiting: 0, Running: 5. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,496-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=T0510D1.rama_map
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,497-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1-1268328759299) setting status to Completed
>> 2010-03-11 11:32:51,497-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-1-1268328759299)
>> Completed. Waiting: 0, Running: 5. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,497-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759322) setting status to Submitting
>> 2010-03-11 11:32:51,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-7-1268328759312) setting status to Active
>> 2010-03-11 11:32:51,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759322) setting status to Submitted
>> 2010-03-11 11:32:51,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759322) setting status to Active
>> 2010-03-11 11:32:51,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-7-1268328759312) setting status to Completed
>> 2010-03-11 11:32:51,498-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-7-1268328759312)
>> Completed. Waiting: 0, Running: 4. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,499-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-9-1268328759324) setting status to Submitting
>> 2010-03-11 11:32:51,499-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-9-1268328759324) setting status to Submitted
>> 2010-03-11 11:32:51,499-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-9-1268328759324) setting status to Active
>> 2010-03-11 11:32:51,500-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-9-1268328759324) setting status to Completed
>> 2010-03-11 11:32:51,500-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-9-1268328759324)
>> Completed. Waiting: 0, Running: 3. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,500-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-5-1268328759326) setting status to Submitting
>> 2010-03-11 11:32:51,500-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-5-1268328759326) setting status to Submitted
>> 2010-03-11 11:32:51,500-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-5-1268328759326) setting status to Active
>> 2010-03-11 11:32:51,500-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-5-1268328759326) setting status to Completed
>> 2010-03-11 11:32:51,500-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-5-1268328759326)
>> Completed. Waiting: 0, Running: 2. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,498-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-4-1268328759293)
>> Completed. Waiting: 0, Running: 4. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,498-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=T0510D1.rama_index
>> srcdir=psim.loops-20100311-1132-4huo5g08/shared/output/data/
>> srchost=localhost destdir=output/data/ desthost=localhost
>> provider=file
>> 2010-03-11 11:32:51,501-0600 DEBUG vdl:dostageout FILE_STAGE_OUT_END
>> srcname=void srcdir=psim.loops-20100311-1132-4huo5g08/shared/
>> srchost=localhost destdir= desthost=localhost provider=file
>> 2010-03-11 11:32:51,501-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759328) setting status to Submitting
>> 2010-03-11 11:32:51,498-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-3-1268328759322) setting status to Completed
>> 2010-03-11 11:32:51,502-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759328) setting status to Submitted
>> 2010-03-11 11:32:51,502-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-3-1268328759322)
>> Completed. Waiting: 0, Running: 2. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,502-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759328) setting status to Active
>> 2010-03-11 11:32:51,503-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-4-1268328759330) setting status to Submitting
>> 2010-03-11 11:32:51,503-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-1-1268328759328) setting status to Completed
>> 2010-03-11 11:32:51,503-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-4-1268328759330) setting status to Submitted
>> 2010-03-11 11:32:51,503-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-1-1268328759328)
>> Completed. Waiting: 0, Running: 1. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,503-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-4-1268328759330) setting status to Active
>> 2010-03-11 11:32:51,503-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-8-1-4-1268328759330) setting status to Completed
>> 2010-03-11 11:32:51,504-0600 INFO LateBindingScheduler
>> Task(type=FILE_OPERATION, identity=urn:0-1-8-1-4-1268328759330)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,506-0600 INFO vdl:dostageout END
>> jobid=PrepLoop-nqsbkyoj - Staging out finished
>> 2010-03-11 11:32:51,512-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759332) setting status to Submitting
>> 2010-03-11 11:32:51,512-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759332) setting status to Submitted
>> 2010-03-11 11:32:51,512-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759332) setting status to Active
>> 2010-03-11 11:32:51,513-0600 DEBUG TaskImpl Task(type=FILE_TRANSFER,
>> identity=urn:0-1-8-1-1268328759332) setting status to Completed
>> 2010-03-11 11:32:51,513-0600 INFO LateBindingScheduler
>> Task(type=FILE_TRANSFER, identity=urn:0-1-8-1-1268328759332)
>> Completed. Waiting: 0, Running: 0. Heap size: 9M, Heap free: 0M, Max
>> heap: 254M
>> 2010-03-11 11:32:51,516-0600 DEBUG vdl:execute2 JOB_END
>> jobid=PrepLoop-nqsbkyoj
>> 2010-03-11 11:32:51,517-0600 INFO vdl:execute END_SUCCESS
>> thread=0-1-8 tr=PrepLoop
>> 2010-03-11 11:32:52,179-0600 INFO CloseDataset Closing
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (not closed)
>> 2010-03-11 11:32:52,179-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (closed)
>> 2010-03-11 11:32:52,179-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000041
>> type SecSeq with no value at dataset=modelData path=.secseq (closed)
>> 2010-03-11 11:32:52,179-0600 INFO AbstractDataNode Notifying listener
>> "F/org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000036
>> type RamaIndex with no value at dataset=modelData path=.index
>> (closed)" about "org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000036
>> type RamaIndex with no value at dataset=modelData path=.index
>> (closed)"
>> 2010-03-11 11:32:52,179-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000036
>> type RamaIndex with no value at dataset=modelData path=.index (closed)
>> 2010-03-11 11:32:52,180-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000037
>> type ProtlibParams with no value at dataset=modelData path=.params
>> (closed)
>> 2010-03-11 11:32:52,180-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000035
>> type PDB with no value at dataset=modelData path=.native (closed)
>> 2010-03-11 11:32:52,180-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000040
>> type RamaMap with no value at dataset=modelData path=.map (closed)
>> 2010-03-11 11:32:52,180-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000038
>> type LoopRange with no value at dataset=modelData path=.range (closed)
>> 2010-03-11 11:32:52,180-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000039
>> type Rama with no value at dataset=modelData path=.rama (closed)
>> 2010-03-11 11:32:52,180-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000034
>> type PDB with no value at dataset=modelData path=.pdb (closed)
>> 2010-03-11 11:32:52,180-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.DataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000033
>> type Fasta with no value at dataset=modelData path=.fasta (closed)
>> 2010-03-11 11:32:52,180-0600 INFO loopprepare PROCEDURE_END line=112
>> 2010-03-11 11:32:52,180-0600 INFO CloseDataset Partially closing
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (closed) for
>> statement 88016
>> 2010-03-11 11:32:52,180-0600 INFO CloseDataset var is
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000021
>> type LoopModelData with no value at dataset=modelData (closed)
>> 2010-03-11 11:32:52,181-0600 INFO CloseDataset var hash is 18923308
>> 2010-03-11 11:32:52,181-0600 INFO CloseDataset variable already
>> closed - skipping partial close processing
>> 2010-03-11 11:32:52,186-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000057
>> type string value=output/data//T0510D1.pdb dataset=unnamed SwiftScript
>> value (closed)
>> 2010-03-11 11:32:52,186-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451007
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000034
>> name=input
>> 2010-03-11 11:32:52,186-0600 INFO VDLFunction FUNCTION id=451007
>> name=filename
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000057
>> 2010-03-11 11:32:52,187-0600 INFO AbstractDataNode closed
>> org.griphyn.vdl.mapping.RootDataNode identifier
>> tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000058
>> type string value=output/run/T0510D1.0.pdb dataset=unnamed SwiftScript
>> value (closed)
>> 2010-03-11 11:32:52,187-0600 INFO VDLFunction FUNCTIONPARAMETER
>> id=451008
>> input=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000053
>> name=input
>> 2010-03-11 11:32:52,187-0600 INFO VDLFunction FUNCTION id=451008
>> name=filename
>> result=tag:benc at ci.uchicago.edu,2008:swift:dataset:20100311-1132-b8hclef8:720000000058
>> 2010-03-11 11:32:52,191-0600 INFO vdl:execute START
>> thread=0-1-9-1-1-1 tr=LoopModel
>> 2010-03-11 11:32:52,193-0600 INFO WeightedHostScoreScheduler Sorted:
>> [coasterpads:10,000.000(99.854):0/50 overload: 0]
>> 2010-03-11 11:32:52,194-0600 INFO WeightedHostScoreScheduler
>> CONTACT_SELECTED host=coasterpads, score=99.854
>> 2010-03-11 11:32:52,195-0600 INFO vdl:initshareddir START
>> host=coasterpads - Initializing shared directory
>> 2010-03-11 11:32:52,198-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-9-1-1-1-1-1268328759336) setting status to Submitting
>> 2010-03-11 11:32:52,261-0600 INFO ConfigurationLoader JAVA version is
>> 1.5.0_07
>> 2010-03-11 11:32:52,282-0600 INFO SshCipherFactory Loading supported
>> cipher algorithms
>> 2010-03-11 11:32:52,287-0600 INFO SshKeyExchangeFactory Loading key
>> exchange methods
>> 2010-03-11 11:32:52,295-0600 INFO SshKeyPairFactory Loading public
>> key algorithms
>> 2010-03-11 11:32:52,303-0600 INFO SshCompressionFactory Loading
>> compression methods
>> 2010-03-11 11:32:52,305-0600 INFO SshHmacFactory Loading message
>> authentication methods
>> 2010-03-11 11:32:52,316-0600 INFO HostKeyVerification Determining
>> default host file
>> 2010-03-11 11:32:52,316-0600 INFO HostKeyVerification Defaulting host
>> file to /home/wwj/.globus/conf/hosts.xml
>> 2010-03-11 11:32:52,487-0600 INFO TransportProtocolCommon Starting
>> transport protocol
>> 2010-03-11 11:32:52,489-0600 INFO TransportProtocolCommon Registering
>> transport protocol messages with inputstream
>> 2010-03-11 11:32:52,799-0600 INFO TransportProtocolCommon Negotiating
>> protocol version
>> 2010-03-11 11:32:52,800-0600 INFO TransportProtocolCommon Protocol
>> negotiation complete
>> 2010-03-11 11:32:52,800-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_KEX_INIT
>> 2010-03-11 11:32:52,806-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_KEX_INIT
>> 2010-03-11 11:32:52,806-0600 INFO TransportProtocolCommon Starting
>> key exchange
>> 2010-03-11 11:32:52,806-0600 INFO DhGroup1Sha1 Starting client side
>> key exchange.
>> 2010-03-11 11:32:52,904-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_KEXDH_INIT
>> 2010-03-11 11:32:52,947-0600 INFO HostKeyVerification Verifying
>> login.pads.ci.uchicago.edu,192.5.86.6 host key
>> 2010-03-11 11:32:52,964-0600 INFO TransportProtocolCommon The host
>> key signature is valid
>> 2010-03-11 11:32:52,964-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_NEWKEYS
>> 2010-03-11 11:32:52,965-0600 INFO TransportProtocolCommon Completing
>> key exchange
>> 2010-03-11 11:32:52,965-0600 INFO SshCipherFactory Creating new
>> 3des-cbc cipher instance
>> 2010-03-11 11:32:53,036-0600 INFO SshCipherFactory Creating new
>> 3des-cbc cipher instance
>> 2010-03-11 11:32:53,048-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_SERVICE_REQUEST
>> 2010-03-11 11:32:53,053-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_SERVICE_ACCEPT
>> 2010-03-11 11:32:53,075-0600 INFO SshPrivateKeyFile Parsing private
>> key file
>> 2010-03-11 11:32:53,084-0600 INFO SshPrivateKeyFile Private key is
>> not in the default format, attempting parse with other supported
>> formats
>> 2010-03-11 11:32:53,105-0600 INFO PublicKeyAuthenticationClient
>> Generating data to sign
>> 2010-03-11 11:32:53,106-0600 INFO PublicKeyAuthenticationClient
>> Preparing public key authentication request
>> 2010-03-11 11:32:53,139-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_USERAUTH_REQUEST
>> 2010-03-11 11:32:53,181-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_USERAUTH_SUCCESS
>> 2010-03-11 11:32:53,181-0600 INFO ConnectionProtocol Registering
>> connection protocol messages
>> 2010-03-11 11:32:53,184-0600 INFO Service ssh-connection has been
>> requested
>> 2010-03-11 11:32:53,184-0600 INFO Service Starting ssh-connection
>> service thread
>> 2010-03-11 11:32:53,190-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_OPEN
>> 2010-03-11 11:32:53,193-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_CHANNEL_OPEN_CONFIRMATION
>> 2010-03-11 11:32:53,194-0600 INFO ConnectionProtocol Channel 0 is
>> open [Unnamed Channel]
>> 2010-03-11 11:32:53,216-0600 INFO SessionChannelClient Starting sftp
>> subsystem
>> 2010-03-11 11:32:53,216-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_REQUEST
>> 2010-03-11 11:32:53,220-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_CHANNEL_WINDOW_ADJUST
>> 2010-03-11 11:32:53,220-0600 INFO Service Routing
>> SSH_MSG_CHANNEL_WINDOW_ADJUST
>> 2010-03-11 11:32:53,221-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_CHANNEL_SUCCESS
>> 2010-03-11 11:32:53,221-0600 INFO SftpSubsystemClient Initializing
>> SFTP protocol version 3
>> 2010-03-11 11:32:53,221-0600 INFO SubsystemClient Sending
>> SSH_FXP_INIT subsystem message
>> 2010-03-11 11:32:53,222-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:53,222-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,520-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,520-0600 INFO Service Routing
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,521-0600 INFO SubsystemMessageStore Received
>> SSH_FXP_INIT subsystem message
>> 2010-03-11 11:32:55,521-0600 INFO SftpSubsystemClient Server
>> responded with version 3
>> 2010-03-11 11:32:55,521-0600 INFO SubsystemClient Sending
>> SSH_FXP_READPATH subsystem message
>> 2010-03-11 11:32:55,521-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,521-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,522-0600 INFO SftpMessageStore Message store has
>> 0 messages
>> 2010-03-11 11:32:55,522-0600 INFO SftpMessageStore Message store has
>> 0 messages
>> 2010-03-11 11:32:55,525-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,525-0600 INFO Service Routing
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,529-0600 INFO SubsystemMessageStore Received
>> SSH_FXP_NAME subsystem message
>> 2010-03-11 11:32:55,529-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-9-1-1-1-1-1268328759336) setting status to Submitted
>> 2010-03-11 11:32:55,529-0600 DEBUG TaskImpl Task(type=FILE_OPERATION,
>> identity=urn:0-1-9-1-1-1-1-1268328759336) setting status to Active
>> 2010-03-11 11:32:55,530-0600 INFO SubsystemClient Sending
>> SSH_FXP_STAT subsystem message
>> 2010-03-11 11:32:55,530-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,530-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:55,530-0600 INFO SftpMessageStore Message store has
>> 0 messages
>> 2010-03-11 11:32:55,530-0600 INFO SftpMessageStore Message store has
>> 0 messages
>> 2010-03-11 11:32:56,167-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:56,167-0600 INFO Service Routing
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:56,168-0600 INFO SubsystemMessageStore Received
>> SSH_FXP_STATUS subsystem message
>> 2010-03-11 11:32:56,168-0600 INFO SubsystemClient Sending
>> SSH_FXP_STAT subsystem message
>> 2010-03-11 11:32:56,168-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:56,168-0600 INFO TransportProtocolCommon Sending
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:56,169-0600 INFO SftpMessageStore Message store has
>> 0 messages
>> 2010-03-11 11:32:56,169-0600 INFO SftpMessageStore Message store has
>> 0 messages
>> 2010-03-11 11:32:56,172-0600 INFO TransportProtocolCommon Received
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:56,172-0600 INFO Service Routing
>> SSH_MSG_CHANNEL_DATA
>> 2010-03-11 11:32:56,172-0600 INFO SubsystemMessageStore Received
>> SSH_FXP_STATUS subsystem message
>> 2010-03-11 11:32:56,172-0600 INFO SubsystemClient Sending
>> SSH_FXP_STAT subsystem message
>> 2010-03-11 11:32:56,172-0600 INFO TransportProtocolC
>>
>
>
More information about the Swift-devel
mailing list