2014-05-06 17:27:57,959-0500 DEBUG Loader arguments: [-tc.file, apps, -sites.file, sites.xml, -config, swift.properties, df.swift, -data=./1goo]
2014-05-06 17:27:57,961-0500 DEBUG Loader Max heap: 7635533824
2014-05-06 17:27:57,963-0500 DEBUG textfiles BEGIN SWIFTSCRIPT:
type file;
type script;

// Note that to use `bash` here, it has to be in SWIFT's 'apps' file:
app (file df, file err, file out) wrapper (script wrap, script df_script, file all_files[]) {
    // this uses bash to call the wrapper script with two CLAs: directory (of input files) and target output file df
    // It also sets stderr and stdout to two passed files, err and out.
    bash @wrap @df @all_files stderr=@err stdout=@out;
}

string dir    = (@arg("data"));
script calc_df  <"df.py">;
script wrap     <"wrapper.sh">;

// This grabs all *.txt files in dir:
file[] all_docs <filesys_mapper; location=dir, suffix=".txt">;

foreach list_of_files, index in all_docs {
    // Top file is for the results -- if this is not created by our python, swift will fail.

    file df  <single_file_mapper; file=@strcat(@list_of_files, ".csv")>;
    file err <single_file_mapper; file=@strcat(@list_of_files, ".err")>;
    file out <single_file_mapper; file=@strcat(@list_of_files, ".out")>;

    // Read the list of files as an array of string which is then passed
    // to the array mapper as the array of filenames for mapping.
    string names[] = readData(list_of_files);
    file all_files[] <array_mapper; files=names >;
    // Do we need to ?
    // Note we have to pass both dir and doc along with the wrapper script and the actual python script: 

    (df,err,out) = wrapper (wrap, calc_df, all_files);
    tracef("WCC Trace: %s\n", @filename(list_of_files));
}



2014-05-06 17:27:57,963-0500 DEBUG textfiles END SWIFTSCRIPT:
2014-05-06 17:27:57,963-0500 DEBUG Loader kmlversion is >76dcc8fd-bbee-4460-aecc-b7e72b83006c-no-provenance<
2014-05-06 17:27:57,963-0500 DEBUG Loader build version is >76dcc8fd-bbee-4460-aecc-b7e72b83006c-no-provenance<
2014-05-06 17:27:57,963-0500 DEBUG Loader Recompilation suppressed.
2014-05-06 17:27:58,079-0500 DEBUG Loader setting: sites.file to: sites.xml
2014-05-06 17:27:58,079-0500 DEBUG Loader setting: tc.file to: apps
2014-05-06 17:27:58,079-0500 DEBUG Loader Swift configuration ([swift.properties]): {pgraph.node.options=color="seagreen", style="filled", clustering.min.time=60, clustering.queue.delay=4, sites.file=sites.xml, ticker.prefix=Progress:  time:, provenance.log=false, kickstart.enabled=maybe, tc.file=apps, foreach.max.threads=16384, lazy.errors=false, ticker.date.format=, sitedir.keep=false, throttle.score.job.factor=0.2, kickstart.always.transfer=false, throttle.host.submit=2, replication.limit=3, clustering.enabled=false, pgraph=false, file.gc.enabled=true, replication.min.queue.time=60, wrapper.parameter.mode=args, replication.enabled=false, throttle.transfers=50, wrapperlog.always.transfer=false, throttle.submit=4, pgraph.graph.options=splines="compound", rankdir="TB", caching.algorithm=LRU, use.wrapper.staging=false, provider.staging.pin.swiftfiles=false, tracing.enabled=false, wrapper.invocation.mode=absolute, mapping.checker=on, execution.retries=0, cdm.broadcast.mode=file, status.mode=files, use.provider.staging=true, throttle.file.operations=8}
2014-05-06 17:27:58,080-0500 DEBUG textfiles BEGIN SITES:
<?xml version="1.0" encoding="UTF-8"?>
<config xmlns="http://www.ci.uchicago.edu/swift/SwiftSites">
  <pool handle="osg">
    <execution provider="coaster" url="login01.osgconnect.net" jobmanager="local:condor"/>
    <!--<execution provider="coaster" url="login01.osgconnect.net" jobmanager="local:local"/>--> <!--For local run-->
    <profile namespace="karajan" key="jobThrottle">12.00</profile>
    <profile namespace="karajan" key="initialScore">10000</profile>
    <profile namespace="globus" key="jobsPerNode">1</profile>
    <profile namespace="globus" key="maxtime">14400</profile>
    <profile namespace="globus" key="maxWalltime">03:55:00</profile>
    <profile namespace="globus" key="highOverAllocation">100</profile>
    <profile namespace="globus" key="lowOverAllocation">100</profile>
    <profile namespace="globus" key="slots">1000</profile>
    <profile namespace="globus" key="maxNodes">1</profile>
    <profile namespace="globus" key="nodeGranularity">1</profile>
    <profile namespace="globus" key="jobType">nonshared</profile>
    <profile namespace="globus" key="condor.+ProjectName">"KnowledgeLab"</profile>
    <!--<profile namespace="globus" key="condor.+RequiresWholeMachine">True</profile>-->
    <!-- <profile namespace="globus" key="condor.Requirements">(regexp("uc3-c*", Machine))</profile> -->
    <!--<profile namespace="globus" key="condor.Requirements">(Target.CAN_RUN_WHOLE_MACHINE =?= True)</profile>-->
    <!--<profile namespace="globus" key="condor.Requirements">(HAS_CVMFS =?= TRUE)</profile>-->
    <!--<profile namespace="globus" key="softImage">/.../nltkenv.tar.gz /tmp/{env.USER}-{env.JOBID}/softimage/</profile>-->
    <!--<workdirectory>/home/{env.USER}/swift-work</workdirectory>--> <!--Need this for local run-->
    <workdirectory>.</workdirectory> <!--Remove this for local run-->
  </pool>
</config>



2014-05-06 17:27:58,080-0500 DEBUG textfiles END SITES:
2014-05-06 17:27:58,086-0500 DEBUG VDL2ExecutionContext Stack dump:
Level 1
[iA = 0, iB = 0, bA = false, bB = false]
	vdl:instanceconfigfile = swift.properties
	vdl:instanceconfig = Swift configuration ([swift.properties]): {pgraph.node.options=color="seagreen", style="filled", clustering.min.time=60, clustering.queue.delay=4, sites.file=sites.xml, ticker.prefix=Progress:  time:, provenance.log=false, kickstart.enabled=maybe, tc.file=apps, foreach.max.threads=16384, lazy.errors=false, ticker.date.format=, sitedir.keep=false, throttle.score.job.factor=0.2, kickstart.always.transfer=false, throttle.host.submit=2, replication.limit=3, clustering.enabled=false, pgraph=false, file.gc.enabled=true, replication.min.queue.time=60, wrapper.parameter.mode=args, replication.enabled=false, throttle.transfers=50, wrapperlog.always.transfer=false, throttle.submit=4, pgraph.graph.options=splines="compound", rankdir="TB", caching.algorithm=LRU, use.wrapper.staging=false, provider.staging.pin.swiftfiles=false, tracing.enabled=false, wrapper.invocation.mode=absolute, mapping.checker=on, execution.retries=0, cdm.broadcast.mode=file, status.mode=files, use.provider.staging=true, throttle.file.operations=8}
	vdl:operation = run
	PATH_SEPARATOR = /
	swift.home = /usr/local/swift/stable/bin/..


2014-05-06 17:27:58,086-0500 INFO  VDL2ExecutionContext swift.home = /usr/local/swift/stable/bin/..
2014-05-06 17:27:58,605-0500 INFO  swift Using sites file: sites.xml
2014-05-06 17:27:58,628-0500 INFO  swift Using tc.data: apps
2014-05-06 17:27:58,715-0500 INFO  AbstractScheduler Setting resources to: {osg=osg}
2014-05-06 17:27:59,106-0500 INFO  swift Swift 0.94.2 RC2 swift-r7209 cog-r3810

2014-05-06 17:27:59,107-0500 INFO  swift RUNID id=run:20140506-1727-39v1is9b
2014-05-06 17:27:59,162-0500 INFO  RuntimeStats$ProgressTicker 
2014-05-06 17:27:59,162-0500 INFO  VDLFunction FUNCTION: arg()
2014-05-06 17:27:59,169-0500 DEBUG swift FOREACH_IT_START line=18 thread=0-2-0
2014-05-06 17:27:59,169-0500 DEBUG swift SCOPE thread=0-2-0
2014-05-06 17:27:59,174-0500 DEBUG swift INTERNALPROC_START thread=0-2-0-5 name=tracef
2014-05-06 17:27:59,174-0500 INFO  Tracef WCC Trace: ./1goo/f0001b.txt

2014-05-06 17:27:59,174-0500 DEBUG swift PROCEDURE line=5 thread=0-2-0-4 name=wrapper
2014-05-06 17:27:59,175-0500 DEBUG swift INTERNALPROC_END thread=0-2-0-5 name=tracef
2014-05-06 17:27:59,175-0500 DEBUG swift INTERNALPROC_START thread=0-2-0-3 name=read_data
2014-05-06 17:27:59,176-0500 DEBUG swift INTERNALPROC_END thread=0-2-0-3 name=read_data
2014-05-06 17:27:59,187-0500 INFO  swift START thread=0-2-0-4 tr=bash
2014-05-06 17:27:59,196-0500 INFO  WeightedHostScoreScheduler Sorted: [osg:10,000.000(99.854):0/1199 overload: 0]
2014-05-06 17:27:59,196-0500 INFO  WeightedHostScoreScheduler CONTACT_SELECTED host=osg, score=99.854
2014-05-06 17:27:59,199-0500 INFO  GlobalSubmitQueue No global submit throttle set. Using default (1024)
2014-05-06 17:27:59,200-0500 INFO  LateBindingScheduler jobs queued: 0
2014-05-06 17:27:59,201-0500 INFO  LateBindingScheduler jobs queued: 0
2014-05-06 17:27:59,203-0500 DEBUG swift THREAD_ASSOCIATION jobid=bash-nxdye9ql thread=0-2-0-4-1 host=osg replicationGroup=mxdye9ql
2014-05-06 17:27:59,207-0500 DEBUG swift JOB_START jobid=bash-nxdye9ql tr=bash arguments=[wrapper.sh, ./1goo/f0001b.txt.csv, stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/2x/7c/ark+=13960=t8bg32x7c/ark+=13960=t8bg32x7c.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/30/47/ark+=13960=t8bg33047/ark+=13960=t8bg33047.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/34/ark+=13960=t8bg35z34/ark+=13960=t8bg35z34.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/72/ark+=13960=t8bg35z72/ark+=13960=t8bg35z72.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/fr/66/ark+=13960=t8bg3fr66/ark+=13960=t8bg3fr66.zip] tmpdir=df-20140506-1727-39v1is9b/jobs/n/bash-nxdye9ql host=osg
2014-05-06 17:27:59,208-0500 DEBUG textfiles BEGIN TC:
local1 cat /bin/cat
local1 bash /bin/bash
local1 sh /bin/bash
local1 python /tmp/df_counter_v2/nltkenv/bin/python
osg python /tmp/df_counter_v2/nltkenv/bin/python
osg sh /bin/bash
osg bash /bin/bash
osg cat /bin/cat


2014-05-06 17:27:59,208-0500 DEBUG textfiles END TC:
2014-05-06 17:27:59,222-0500 INFO  GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-2-0-4-1-1399415278619) is /bin/bash _swiftwrap.staging -e /bin/bash -out ./1goo/f0001b.txt.out -err ./1goo/f0001b.txt.err -i -d ./1goo -if wrapper.sh|df.py|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/2x/7c/ark+=13960=t8bg32x7c/ark+=13960=t8bg32x7c.zip|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/30/47/ark+=13960=t8bg33047/ark+=13960=t8bg33047.zip|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/34/ark+=13960=t8bg35z34/ark+=13960=t8bg35z34.zip|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/72/ark+=13960=t8bg35z72/ark+=13960=t8bg35z72.zip|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/fr/66/ark+=13960=t8bg3fr66/ark+=13960=t8bg3fr66.zip -of ./1goo/f0001b.txt.csv|./1goo/f0001b.txt.err|./1goo/f0001b.txt.out -k -cdmfile  -status provider -a wrapper.sh ./1goo/f0001b.txt.csv stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/2x/7c/ark+=13960=t8bg32x7c/ark+=13960=t8bg32x7c.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/30/47/ark+=13960=t8bg33047/ark+=13960=t8bg33047.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/34/ark+=13960=t8bg35z34/ark+=13960=t8bg35z34.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/72/ark+=13960=t8bg35z72/ark+=13960=t8bg35z72.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/fr/66/ark+=13960=t8bg3fr66/ark+=13960=t8bg3fr66.zip
2014-05-06 17:27:59,248-0500 INFO  LocalService Started local service: 192.170.227.195:53815
2014-05-06 17:27:59,253-0500 INFO  BootstrapService Socket bound. URL is http://login01.osgconnect.net:50652
2014-05-06 17:27:59,282-0500 INFO  Settings Local contacts: [http://192.170.227.195:42745]
2014-05-06 17:27:59,284-0500 INFO  CoasterService Started local service: http://192.170.227.195:42745
2014-05-06 17:27:59,284-0500 INFO  CoasterService Reserving channel for registration
2014-05-06 17:27:59,297-0500 INFO  MetaChannel MetaChannel [context: cpipe, boundTo: null] binding to cpipe://1
2014-05-06 17:27:59,297-0500 INFO  MetaChannel MetaChannel [context: spipe, boundTo: null] binding to spipe://1
2014-05-06 17:27:59,297-0500 INFO  CoasterService Sending registration
2014-05-06 17:27:59,300-0500 INFO  MetaChannel Trying to re-bind current channel
2014-05-06 17:27:59,301-0500 INFO  RequestHandler Handler(tag: 1, REGISTER) unregistering (send)
2014-05-06 17:27:59,301-0500 INFO  CoasterService Registration complete
2014-05-06 17:27:59,301-0500 INFO  CoasterService Started coaster service: http://192.170.227.195:40798
2014-05-06 17:27:59,303-0500 INFO  RequestHandler Handler(tag: 1, CONFIGSERVICE) unregistering (send)
2014-05-06 17:27:59,313-0500 INFO  BlockQueueProcessor Starting... id=0506-2705590
2014-05-06 17:27:59,316-0500 INFO  RequestHandler Handler(tag: 2, SUBMITJOB) unregistering (send)
2014-05-06 17:27:59,316-0500 INFO  BlockQueueProcessor Committed 1 new jobs
2014-05-06 17:28:00,319-0500 INFO  BlockQueueProcessor 
Settings {
	slots = 1000
	jobsPerNode = 1
	workersPerNode = 1
	nodeGranularity = 1
	allocationStepSize = 0.1
	maxNodes = 1
	lowOverallocation = 100.0
	highOverallocation = 100.0
	overallocationDecayFactor = 0.0010
	spread = 0.9
	reserve = 60.000s
	maxtime = 14400
	remoteMonitorEnabled = false
	internalHostname = 192.170.227.195
	hookClass = null
	workerManager = block
	workerLoggingLevel = NONE
	workerLoggingDirectory = DEFAULT
	ldLibraryPath = null
	workerCopies = null
	directory = null
	useHashBang = null
	maxBlockIdleTime = 30
	parallelism = 0.01
	coresPerNode = 1
	attributes = {condor.+projectname="KnowledgeLab", jobtype=nonshared}
}

2014-05-06 17:28:00,319-0500 INFO  BlockQueueProcessor Jobs in holding queue: 1
2014-05-06 17:28:00,319-0500 INFO  BlockQueueProcessor Time estimate for holding queue (seconds): 1
2014-05-06 17:28:00,319-0500 INFO  BlockQueueProcessor Allocating blocks for a total walltime of: 1s
2014-05-06 17:28:00,319-0500 INFO  BlockQueueProcessor 	 Considering: Job(id:0 14100.000s)
2014-05-06 17:28:00,319-0500 INFO  BlockQueueProcessor 	  Max Walltime (seconds):   14100
2014-05-06 17:28:00,319-0500 INFO  BlockQueueProcessor 	  Time estimate (seconds):  14340
2014-05-06 17:28:00,319-0500 INFO  BlockQueueProcessor 	  Total for this new Block (est. seconds): 0
2014-05-06 17:28:00,322-0500 INFO  BlockQueueProcessor index: 0, last: 0, holding.size(): 1
2014-05-06 17:28:00,322-0500 INFO  BlockQueueProcessor Queued: 1 jobs to new Block
2014-05-06 17:28:00,322-0500 INFO  BlockQueueProcessor index: 0, last: 0, ii: 1, holding.size(): 1
2014-05-06 17:28:00,322-0500 INFO  Block Starting block: workers=1, walltime=14340.000s
2014-05-06 17:28:00,323-0500 INFO  RemoteLogHandler BLOCK_REQUESTED id=0506-2705590-000000, workers=1, walltime=14340
2014-05-06 17:28:00,324-0500 INFO  RequestHandler Handler(tag: 2, RLOG) unregistering (send)
2014-05-06 17:28:00,324-0500 INFO  BlockTaskSubmitter Queuing block Block 0506-2705590-000000 (1x14340.000s) for submission
2014-05-06 17:28:00,324-0500 INFO  BlockQueueProcessor Added 1 jobs to new blocks
2014-05-06 17:28:00,325-0500 INFO  BlockTaskSubmitter Submitting block Block 0506-2705590-000000 (1x14340.000s)
2014-05-06 17:28:00,325-0500 INFO  ExecutionTaskHandler provider=condor
2014-05-06 17:28:00,327-0500 INFO  Block Block task status changed: Submitting
2014-05-06 17:28:00,331-0500 DEBUG AbstractExecutor Writing Condor script to /home/wcatino/.globus/scripts/Condor2219113065317641302.submit
2014-05-06 17:28:00,331-0500 DEBUG AbstractExecutor Wrote Condor script to /home/wcatino/.globus/scripts/Condor2219113065317641302.submit
2014-05-06 17:28:00,332-0500 DEBUG AbstractExecutor Command line: condor_submit /home/wcatino/.globus/scripts/Condor2219113065317641302.submit
2014-05-06 17:28:00,417-0500 DEBUG AbstractExecutor condor_submit done (exit code 0)
2014-05-06 17:28:00,417-0500 DEBUG AbstractExecutor Waiting for output from condor_submit
2014-05-06 17:28:00,417-0500 DEBUG AbstractExecutor Output from condor_submit is: "Submitting job(s).1 job(s) submitted to cluster 220980."
2014-05-06 17:28:00,417-0500 DEBUG AbstractExecutor Submitted job with id '220980'
2014-05-06 17:28:00,419-0500 INFO  Block Block task status changed: Submitted
2014-05-06 17:28:00,669-0500 INFO  AbstractQueuePoller Actively monitored: 0, New: 1, Done: 0
2014-05-06 17:28:05,807-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:10,948-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:16,086-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:21,226-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:26,365-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:29,162-0500 INFO  RuntimeStats$ProgressTicker   Submitted:1
2014-05-06 17:28:31,504-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:36,650-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:41,789-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:47,011-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:52,156-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:57,296-0500 INFO  Block Block task status changed: Active
2014-05-06 17:28:57,296-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:28:57,296-0500 INFO  RemoteLogHandler BLOCK_ACTIVE id=0506-2705590-000000
2014-05-06 17:28:57,296-0500 INFO  RequestHandler Handler(tag: 3, RLOG) unregistering (send)
2014-05-06 17:28:58,537-0500 INFO  AbstractKarajanChannel Timeout check started for TCPChannel [type: server, contact: unknown]
2014-05-06 17:28:58,542-0500 INFO  AbstractTCPChannel Channel started: TCPChannel [type: server, contact: 200.136.80.17:37909]
2014-05-06 17:28:58,544-0500 INFO  LocalTCPService Received registration: blockid = 0506-2705590-000000, url = node128.local
2014-05-06 17:28:58,545-0500 INFO  MetaChannel MetaChannel [context: worker-1, boundTo: null] binding to TCPChannel [type: server, contact: 200.136.80.17:37909]
2014-05-06 17:28:58,547-0500 DEBUG Cpu worker started: block=0506-2705590-000000 host=node128.local id=0
2014-05-06 17:28:58,547-0500 DEBUG Cpu ready for work: block=0506-2705590-000000 id=0
2014-05-06 17:28:58,549-0500 INFO  Block Started CPU 0:1399415338s
2014-05-06 17:28:58,549-0500 INFO  Block Started worker 0506-2705590-000000:000000
2014-05-06 17:28:58,549-0500 DEBUG Cpu requesting work: block=0506-2705590-000000 id=0 Cpus sleeping: 1
2014-05-06 17:28:58,549-0500 INFO  AbstractStreamKarajanChannel Using NIO sender for TCPChannel [type: server, contact: 0506-2705590-000000-000000]
2014-05-06 17:28:58,550-0500 INFO  Cpu 0506-2705590-000000:0 (quality: 1.0) submitting urn:1399415278619-1399415278622-1399415278623: /bin/bash _swiftwrap.staging -e /bin/bash -out ./1goo/f0001b.txt.out -err ./1goo/f0001b.txt.err -i -d ./1goo -if wrapper.sh|df.py|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/2x/7c/ark+=13960=t8bg32x7c/ark+=13960=t8bg32x7c.zip|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/30/47/ark+=13960=t8bg33047/ark+=13960=t8bg33047.zip|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/34/ark+=13960=t8bg35z34/ark+=13960=t8bg35z34.zip|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/72/ark+=13960=t8bg35z72/ark+=13960=t8bg35z72.zip|/stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/fr/66/ark+=13960=t8bg3fr66/ark+=13960=t8bg3fr66.zip -of ./1goo/f0001b.txt.csv|./1goo/f0001b.txt.err|./1goo/f0001b.txt.out -k -cdmfile  -status provider -a wrapper.sh ./1goo/f0001b.txt.csv stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/2x/7c/ark+=13960=t8bg32x7c/ark+=13960=t8bg32x7c.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/30/47/ark+=13960=t8bg33047/ark+=13960=t8bg33047.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/34/ark+=13960=t8bg35z34/ark+=13960=t8bg35z34.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/72/ark+=13960=t8bg35z72/ark+=13960=t8bg35z72.zip stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/fr/66/ark+=13960=t8bg3fr66/ark+=13960=t8bg3fr66.zip
2014-05-06 17:28:58,551-0500 INFO  RequestHandler Handler(tag: 4, JOBSTATUS) unregistering (send)
2014-05-06 17:28:58,554-0500 INFO  RequestHandler Handler(tag: 6636, REGISTER) unregistering (send)
2014-05-06 17:28:58,709-0500 INFO  RequestHandler Handler(tag: 5, JOBSTATUS) unregistering (send)
2014-05-06 17:28:58,710-0500 DEBUG Cpu Stagein workerid=000000
2014-05-06 17:28:58,710-0500 INFO  RequestHandler Handler(tag: 6637, JOBSTATUS) unregistering (send)
2014-05-06 17:28:58,710-0500 INFO  RuntimeStats$ProgressTicker   Stage in:1
2014-05-06 17:28:58,710-0500 INFO  RequestHandler Handler(tag: 6, JOBSTATUS) unregistering (send)
2014-05-06 17:28:58,711-0500 INFO  GetFileHandler Handler(tag: 6638, GET) request complete; src=proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//usr/local/swift/stable/bin/../libexec/_swiftwrap.staging
2014-05-06 17:28:58,721-0500 INFO  GetFileHandler Handler(tag: 6638, GET) reader: PR proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//usr/local/swift/stable/bin/../libexec/_swiftwrap.staging
2014-05-06 17:28:58,721-0500 INFO  GetFileHandler Handler(tag: 6638, GET) -> 7
2014-05-06 17:28:58,721-0500 INFO  GetFileHandler Handler(tag: 7, GET) request complete; src=file://localhost//usr/local/swift/stable/bin/../libexec/_swiftwrap.staging
2014-05-06 17:28:58,722-0500 INFO  GetFileHandler Handler(tag: 7, GET) reader: LR-Handler(tag: 7, GET)
2014-05-06 17:28:58,722-0500 INFO  GetFileHandler Handler(tag: 7, GET) sending length: 6078, 233950198
2014-05-06 17:28:58,723-0500 INFO  GetFileHandler Handler(tag: 6638, GET) sending length: 6078, 2105903776
2014-05-06 17:28:58,723-0500 INFO  ReadBuffer RB-LR-Handler(tag: 7, GET) will ask for 1 buffers for a size of 6078
2014-05-06 17:28:58,724-0500 INFO  ReadBuffer RB-LR-Handler(tag: 7, GET) actual allocated buffers 1(0 queued)
2014-05-06 17:28:58,724-0500 INFO  LocalIOProvider LR-Handler(tag: 7, GET) rbuf: RB-LR-Handler(tag: 7, GET)
2014-05-06 17:28:58,724-0500 INFO  Buffers I allocated buffers: {RB-LR-Handler(tag: 7, GET) -> 1} (1)
2014-05-06 17:28:58,724-0500 INFO  GetFileHandler Handler(tag: 7, GET) unregistering (last)
2014-05-06 17:28:58,724-0500 INFO  ReadBuffer RB-LR-Handler(tag: 7, GET) de-allocating 1 buffers
2014-05-06 17:28:58,725-0500 INFO  Buffers O allocated buffers: {POW-Command(tag: -1, GET) -> 1} (1)
2014-05-06 17:28:58,725-0500 INFO  GetFileHandler Handler(tag: 6638, GET) unregistering (last)
2014-05-06 17:28:58,880-0500 INFO  GetFileHandler Handler(tag: 6639, GET) request complete; src=proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/72/ark+=13960=t8bg35z72/ark+=13960=t8bg35z72.zip
2014-05-06 17:28:58,880-0500 INFO  GetFileHandler Handler(tag: 6639, GET) reader: PR proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/72/ark+=13960=t8bg35z72/ark+=13960=t8bg35z72.zip
2014-05-06 17:28:58,880-0500 INFO  GetFileHandler Handler(tag: 6639, GET) -> 8
2014-05-06 17:28:58,880-0500 INFO  GetFileHandler Handler(tag: 8, GET) request complete; src=file://localhost//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/72/ark+=13960=t8bg35z72/ark+=13960=t8bg35z72.zip
2014-05-06 17:28:58,880-0500 INFO  GetFileHandler Handler(tag: 8, GET) reader: LR-Handler(tag: 8, GET)
2014-05-06 17:28:58,880-0500 INFO  GetFileHandler Handler(tag: 8, GET) sending length: 367805, 1235930463
2014-05-06 17:28:58,880-0500 INFO  GetFileHandler Handler(tag: 6639, GET) sending length: 367805, 1821457857
2014-05-06 17:28:58,880-0500 INFO  ReadBuffer RB-LR-Handler(tag: 8, GET) will ask for 8 buffers for a size of 367805
2014-05-06 17:28:58,880-0500 INFO  ReadBuffer RB-LR-Handler(tag: 8, GET) actual allocated buffers 8(0 queued)
2014-05-06 17:28:58,880-0500 INFO  LocalIOProvider LR-Handler(tag: 8, GET) rbuf: RB-LR-Handler(tag: 8, GET)
2014-05-06 17:28:58,881-0500 INFO  GetFileHandler Handler(tag: 8, GET) unregistering (last)
2014-05-06 17:28:58,881-0500 INFO  ReadBuffer RB-LR-Handler(tag: 8, GET) de-allocating 8 buffers
2014-05-06 17:28:58,881-0500 INFO  GetFileHandler Handler(tag: 6639, GET) unregistering (last)
2014-05-06 17:28:58,882-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:28:58,882-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:28:58,882-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:28:58,882-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:28:58,882-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:28:58,882-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:28:59,336-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:28:59,337-0500 INFO  ThrottleManager mem=139.47 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:28:59,382-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:28:59,837-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:28:59,837-0500 INFO  ThrottleManager mem=139.47 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:28:59,882-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:00,337-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:00,338-0500 INFO  ThrottleManager mem=139.47 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:00,382-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:00,741-0500 INFO  GetFileHandler Handler(tag: 6640, GET) request complete; src=proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//home/wcatino/df/./df.py
2014-05-06 17:29:00,741-0500 INFO  GetFileHandler Handler(tag: 6640, GET) reader: PR proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//home/wcatino/df/./df.py
2014-05-06 17:29:00,741-0500 INFO  GetFileHandler Handler(tag: 6640, GET) -> 9
2014-05-06 17:29:00,741-0500 INFO  GetFileHandler Handler(tag: 9, GET) request complete; src=file://localhost//home/wcatino/df/df.py
2014-05-06 17:29:00,742-0500 INFO  GetFileHandler Handler(tag: 9, GET) reader: LR-Handler(tag: 9, GET)
2014-05-06 17:29:00,742-0500 INFO  GetFileHandler Handler(tag: 9, GET) sending length: 3443, 1629818866
2014-05-06 17:29:00,742-0500 INFO  GetFileHandler Handler(tag: 6640, GET) sending length: 3443, 1211763377
2014-05-06 17:29:00,742-0500 INFO  ReadBuffer RB-LR-Handler(tag: 9, GET) will ask for 1 buffers for a size of 3443
2014-05-06 17:29:00,742-0500 INFO  ReadBuffer RB-LR-Handler(tag: 9, GET) actual allocated buffers 1(0 queued)
2014-05-06 17:29:00,742-0500 INFO  LocalIOProvider LR-Handler(tag: 9, GET) rbuf: RB-LR-Handler(tag: 9, GET)
2014-05-06 17:29:00,742-0500 INFO  GetFileHandler Handler(tag: 9, GET) unregistering (last)
2014-05-06 17:29:00,742-0500 INFO  GetFileHandler Handler(tag: 6640, GET) unregistering (last)
2014-05-06 17:29:00,742-0500 INFO  ReadBuffer RB-LR-Handler(tag: 9, GET) de-allocating 1 buffers
2014-05-06 17:29:00,895-0500 INFO  GetFileHandler Handler(tag: 6641, GET) request complete; src=proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/34/ark+=13960=t8bg35z34/ark+=13960=t8bg35z34.zip
2014-05-06 17:29:00,895-0500 INFO  GetFileHandler Handler(tag: 6641, GET) reader: PR proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/34/ark+=13960=t8bg35z34/ark+=13960=t8bg35z34.zip
2014-05-06 17:29:00,895-0500 INFO  GetFileHandler Handler(tag: 6641, GET) -> 10
2014-05-06 17:29:00,895-0500 INFO  GetFileHandler Handler(tag: 10, GET) request complete; src=file://localhost//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/5z/34/ark+=13960=t8bg35z34/ark+=13960=t8bg35z34.zip
2014-05-06 17:29:00,895-0500 INFO  GetFileHandler Handler(tag: 10, GET) reader: LR-Handler(tag: 10, GET)
2014-05-06 17:29:00,895-0500 INFO  GetFileHandler Handler(tag: 10, GET) sending length: 342975, 1800671559
2014-05-06 17:29:00,895-0500 INFO  GetFileHandler Handler(tag: 6641, GET) sending length: 342975, 1547338589
2014-05-06 17:29:00,895-0500 INFO  ReadBuffer RB-LR-Handler(tag: 10, GET) will ask for 8 buffers for a size of 342975
2014-05-06 17:29:00,895-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=5, allowedTransfers=252, active=0, suspended=0
2014-05-06 17:29:00,895-0500 INFO  ReadBuffer RB-LR-Handler(tag: 10, GET) actual allocated buffers 8(0 queued)
2014-05-06 17:29:00,895-0500 INFO  LocalIOProvider LR-Handler(tag: 10, GET) rbuf: RB-LR-Handler(tag: 10, GET)
2014-05-06 17:29:00,895-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=1, allowedTransfers=255, active=0, suspended=0
2014-05-06 17:29:00,896-0500 INFO  ThrottleManager mem=139.6 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:00,896-0500 INFO  GetFileHandler Handler(tag: 10, GET) unregistering (last)
2014-05-06 17:29:00,896-0500 INFO  GetFileHandler Handler(tag: 6641, GET) unregistering (last)
2014-05-06 17:29:00,897-0500 INFO  ReadBuffer RB-LR-Handler(tag: 10, GET) de-allocating 8 buffers
2014-05-06 17:29:00,897-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:00,897-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:00,897-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:00,897-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:00,897-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:00,897-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:01,397-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:01,699-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:01,699-0500 INFO  ThrottleManager mem=140.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:01,897-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:02,200-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:02,200-0500 INFO  ThrottleManager mem=140.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:02,398-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:02,435-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:02,454-0500 INFO  GetFileHandler Handler(tag: 6642, GET) request complete; src=proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/fr/66/ark+=13960=t8bg3fr66/ark+=13960=t8bg3fr66.zip
2014-05-06 17:29:02,454-0500 INFO  GetFileHandler Handler(tag: 6642, GET) reader: PR proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/fr/66/ark+=13960=t8bg3fr66/ark+=13960=t8bg3fr66.zip
2014-05-06 17:29:02,454-0500 INFO  GetFileHandler Handler(tag: 6642, GET) -> 11
2014-05-06 17:29:02,454-0500 INFO  GetFileHandler Handler(tag: 11, GET) request complete; src=file://localhost//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/fr/66/ark+=13960=t8bg3fr66/ark+=13960=t8bg3fr66.zip
2014-05-06 17:29:02,455-0500 INFO  GetFileHandler Handler(tag: 11, GET) reader: LR-Handler(tag: 11, GET)
2014-05-06 17:29:02,455-0500 INFO  GetFileHandler Handler(tag: 11, GET) sending length: 410624, 85031456
2014-05-06 17:29:02,455-0500 INFO  GetFileHandler Handler(tag: 6642, GET) sending length: 410624, 1047055737
2014-05-06 17:29:02,455-0500 INFO  ReadBuffer RB-LR-Handler(tag: 11, GET) will ask for 8 buffers for a size of 410624
2014-05-06 17:29:02,455-0500 INFO  ReadBuffer RB-LR-Handler(tag: 11, GET) actual allocated buffers 8(0 queued)
2014-05-06 17:29:02,455-0500 INFO  LocalIOProvider LR-Handler(tag: 11, GET) rbuf: RB-LR-Handler(tag: 11, GET)
2014-05-06 17:29:02,456-0500 INFO  GetFileHandler Handler(tag: 11, GET) unregistering (last)
2014-05-06 17:29:02,456-0500 INFO  GetFileHandler Handler(tag: 6642, GET) unregistering (last)
2014-05-06 17:29:02,456-0500 INFO  ReadBuffer RB-LR-Handler(tag: 11, GET) de-allocating 8 buffers
2014-05-06 17:29:02,456-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:02,456-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:02,456-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:02,456-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:02,456-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:02,456-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:02,456-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:02,759-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=2, allowedTransfers=255, active=0, suspended=0
2014-05-06 17:29:02,759-0500 INFO  ThrottleManager mem=140.92 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:02,957-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:03,457-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:03,563-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:03,563-0500 INFO  ThrottleManager mem=140.92 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:03,957-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:04,063-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:04,064-0500 INFO  ThrottleManager mem=140.92 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:04,457-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:04,564-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:04,564-0500 INFO  ThrottleManager mem=140.92 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:04,661-0500 INFO  GetFileHandler Handler(tag: 6643, GET) request complete; src=proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/2x/7c/ark+=13960=t8bg32x7c/ark+=13960=t8bg32x7c.zip
2014-05-06 17:29:04,661-0500 INFO  GetFileHandler Handler(tag: 6643, GET) reader: PR proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/2x/7c/ark+=13960=t8bg32x7c/ark+=13960=t8bg32x7c.zip
2014-05-06 17:29:04,661-0500 INFO  GetFileHandler Handler(tag: 6643, GET) -> 12
2014-05-06 17:29:04,661-0500 INFO  GetFileHandler Handler(tag: 12, GET) request complete; src=file://localhost//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/2x/7c/ark+=13960=t8bg32x7c/ark+=13960=t8bg32x7c.zip
2014-05-06 17:29:04,661-0500 INFO  GetFileHandler Handler(tag: 12, GET) reader: LR-Handler(tag: 12, GET)
2014-05-06 17:29:04,661-0500 INFO  GetFileHandler Handler(tag: 12, GET) sending length: 294091, 1466238202
2014-05-06 17:29:04,661-0500 INFO  GetFileHandler Handler(tag: 6643, GET) sending length: 294091, 690611689
2014-05-06 17:29:04,661-0500 INFO  ReadBuffer RB-LR-Handler(tag: 12, GET) will ask for 8 buffers for a size of 294091
2014-05-06 17:29:04,661-0500 INFO  ReadBuffer RB-LR-Handler(tag: 12, GET) actual allocated buffers 8(0 queued)
2014-05-06 17:29:04,661-0500 INFO  LocalIOProvider LR-Handler(tag: 12, GET) rbuf: RB-LR-Handler(tag: 12, GET)
2014-05-06 17:29:04,662-0500 INFO  GetFileHandler Handler(tag: 12, GET) unregistering (last)
2014-05-06 17:29:04,663-0500 INFO  ReadBuffer RB-LR-Handler(tag: 12, GET) de-allocating 8 buffers
2014-05-06 17:29:04,663-0500 INFO  GetFileHandler Handler(tag: 6643, GET) unregistering (last)
2014-05-06 17:29:04,663-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:04,663-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:04,663-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:04,663-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:04,663-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:04,663-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:04,663-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:05,163-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:05,313-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:05,313-0500 INFO  ThrottleManager mem=141.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:05,663-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:05,814-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:05,814-0500 INFO  ThrottleManager mem=141.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:06,029-0500 INFO  GetFileHandler Handler(tag: 6644, GET) request complete; src=proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//home/wcatino/df/./wrapper.sh
2014-05-06 17:29:06,030-0500 INFO  GetFileHandler Handler(tag: 6644, GET) reader: PR proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//home/wcatino/df/./wrapper.sh
2014-05-06 17:29:06,030-0500 INFO  GetFileHandler Handler(tag: 6644, GET) -> 13
2014-05-06 17:29:06,030-0500 INFO  GetFileHandler Handler(tag: 13, GET) request complete; src=file://localhost//home/wcatino/df/wrapper.sh
2014-05-06 17:29:06,030-0500 INFO  GetFileHandler Handler(tag: 13, GET) reader: LR-Handler(tag: 13, GET)
2014-05-06 17:29:06,030-0500 INFO  GetFileHandler Handler(tag: 13, GET) sending length: 1270, 160634233
2014-05-06 17:29:06,030-0500 INFO  ReadBuffer RB-LR-Handler(tag: 13, GET) will ask for 1 buffers for a size of 1270
2014-05-06 17:29:06,030-0500 INFO  GetFileHandler Handler(tag: 6644, GET) sending length: 1270, 392609752
2014-05-06 17:29:06,030-0500 INFO  ReadBuffer RB-LR-Handler(tag: 13, GET) actual allocated buffers 1(0 queued)
2014-05-06 17:29:06,030-0500 INFO  LocalIOProvider LR-Handler(tag: 13, GET) rbuf: RB-LR-Handler(tag: 13, GET)
2014-05-06 17:29:06,030-0500 INFO  GetFileHandler Handler(tag: 13, GET) unregistering (last)
2014-05-06 17:29:06,030-0500 INFO  GetFileHandler Handler(tag: 6644, GET) unregistering (last)
2014-05-06 17:29:06,031-0500 INFO  ReadBuffer RB-LR-Handler(tag: 13, GET) de-allocating 1 buffers
2014-05-06 17:29:06,182-0500 INFO  GetFileHandler Handler(tag: 6645, GET) request complete; src=proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/30/47/ark+=13960=t8bg33047/ark+=13960=t8bg33047.zip
2014-05-06 17:29:06,183-0500 INFO  GetFileHandler Handler(tag: 6645, GET) reader: PR proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/30/47/ark+=13960=t8bg33047/ark+=13960=t8bg33047.zip
2014-05-06 17:29:06,183-0500 INFO  GetFileHandler Handler(tag: 6645, GET) -> 14
2014-05-06 17:29:06,183-0500 INFO  GetFileHandler Handler(tag: 14, GET) request complete; src=file://localhost//stash/shared/hathitrust/english/bc/pairtree_root/ar/k+/=1/39/60/=t/8b/g3/30/47/ark+=13960=t8bg33047/ark+=13960=t8bg33047.zip
2014-05-06 17:29:06,183-0500 INFO  GetFileHandler Handler(tag: 14, GET) reader: LR-Handler(tag: 14, GET)
2014-05-06 17:29:06,183-0500 INFO  GetFileHandler Handler(tag: 14, GET) sending length: 404142, 153523906
2014-05-06 17:29:06,183-0500 INFO  GetFileHandler Handler(tag: 6645, GET) sending length: 404142, 1148428095
2014-05-06 17:29:06,183-0500 INFO  ReadBuffer RB-LR-Handler(tag: 14, GET) will ask for 8 buffers for a size of 404142
2014-05-06 17:29:06,183-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=4, allowedTransfers=253, active=0, suspended=0
2014-05-06 17:29:06,183-0500 INFO  ReadBuffer RB-LR-Handler(tag: 14, GET) actual allocated buffers 8(0 queued)
2014-05-06 17:29:06,183-0500 INFO  LocalIOProvider LR-Handler(tag: 14, GET) rbuf: RB-LR-Handler(tag: 14, GET)
2014-05-06 17:29:06,185-0500 INFO  GetFileHandler Handler(tag: 14, GET) unregistering (last)
2014-05-06 17:29:06,185-0500 INFO  ReadBuffer RB-LR-Handler(tag: 14, GET) de-allocating 8 buffers
2014-05-06 17:29:06,185-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:06,185-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:06,185-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:06,185-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:06,185-0500 INFO  GetFileHandler Handler(tag: 6645, GET) unregistering (last)
2014-05-06 17:29:06,185-0500 INFO  NIOChannelReadBuffer Transfer done. De-allocating one unused buffer
2014-05-06 17:29:06,335-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=4, allowedTransfers=253, active=0, suspended=0
2014-05-06 17:29:06,335-0500 INFO  ThrottleManager mem=142.19 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:06,685-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:07,186-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:07,332-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:07,332-0500 INFO  ThrottleManager mem=142.35 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:07,575-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:07,686-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:07,832-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:07,832-0500 INFO  ThrottleManager mem=142.66 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:08,159-0500 DEBUG Cpu Active workerid=000000
2014-05-06 17:29:08,159-0500 INFO  RequestHandler Handler(tag: 6646, JOBSTATUS) unregistering (send)
2014-05-06 17:29:08,159-0500 INFO  RuntimeStats$ProgressTicker   Active:1
2014-05-06 17:29:08,159-0500 INFO  RequestHandler Handler(tag: 15, JOBSTATUS) unregistering (send)
2014-05-06 17:29:08,186-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:08,332-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:08,333-0500 INFO  ThrottleManager mem=142.66 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:08,338-0500 INFO  PerformanceDiagnosticInputStream [IN] Total transferred: 0 B, current rate: 0 B/s, average rate: 0 B/s
2014-05-06 17:29:08,338-0500 INFO  PerformanceDiagnosticInputStream [MEM] Heap total: 724.56 MB, Heap used: 142.81 MB
2014-05-06 17:29:08,686-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:08,833-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:08,833-0500 INFO  ThrottleManager mem=142.81 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:08,833-0500 INFO  Buffers O allocated buffers: {} (0)
2014-05-06 17:29:09,186-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:09,186-0500 INFO  Buffers I allocated buffers: {} (0)
2014-05-06 17:29:09,333-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:09,333-0500 INFO  ThrottleManager mem=142.81 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:09,687-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:09,833-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:09,833-0500 INFO  ThrottleManager mem=142.81 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:10,187-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:10,333-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:10,334-0500 INFO  ThrottleManager mem=142.81 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:10,687-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:10,834-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:10,834-0500 INFO  ThrottleManager mem=142.81 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:11,187-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:11,334-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:11,334-0500 INFO  ThrottleManager mem=142.81 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:11,687-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:11,834-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:11,834-0500 INFO  ThrottleManager mem=142.81 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:12,187-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:12,334-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:12,335-0500 INFO  ThrottleManager mem=142.81 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:12,688-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:12,719-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:12,835-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:12,835-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:13,188-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:13,335-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:13,335-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:13,688-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:13,835-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:13,835-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:14,188-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:14,336-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:14,336-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:14,688-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:14,836-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:14,836-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:15,189-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:15,336-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:15,336-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:15,689-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:15,836-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:15,836-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:16,189-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:16,336-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:16,337-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:16,689-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:16,837-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:16,837-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:17,189-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:17,337-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:17,337-0500 INFO  ThrottleManager mem=142.97 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:17,689-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:17,837-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:17,837-0500 INFO  ThrottleManager mem=143.13 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:17,857-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:18,190-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:18,337-0500 INFO  PerformanceDiagnosticInputStream [IN] Total transferred: 0 B, current rate: 0 B/s, average rate: 0 B/s
2014-05-06 17:29:18,337-0500 INFO  PerformanceDiagnosticInputStream [MEM] Heap total: 724.56 MB, Heap used: 143.28 MB
2014-05-06 17:29:18,338-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:18,338-0500 INFO  ThrottleManager mem=143.28 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:18,690-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:18,838-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:18,838-0500 INFO  ThrottleManager mem=143.28 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:18,838-0500 INFO  Buffers O allocated buffers: {} (0)
2014-05-06 17:29:19,190-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:19,190-0500 INFO  Buffers I allocated buffers: {} (0)
2014-05-06 17:29:19,338-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:19,338-0500 INFO  ThrottleManager mem=143.28 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:19,690-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:19,838-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:19,839-0500 INFO  ThrottleManager mem=143.28 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:20,190-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:20,339-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:20,339-0500 INFO  ThrottleManager mem=143.43 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:20,691-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:20,839-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:20,839-0500 INFO  ThrottleManager mem=143.43 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:21,191-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:21,339-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:21,339-0500 INFO  ThrottleManager mem=143.43 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:21,691-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:21,839-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:21,840-0500 INFO  ThrottleManager mem=143.43 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:22,191-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:22,340-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:22,340-0500 INFO  ThrottleManager mem=143.43 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:22,691-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:22,840-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:22,840-0500 INFO  ThrottleManager mem=143.43 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:22,997-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:23,192-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:23,340-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:23,340-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:23,692-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:23,840-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:23,840-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:24,192-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:24,341-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:24,341-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:24,692-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:24,841-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:24,841-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:25,192-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:25,341-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:25,341-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:25,692-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:25,841-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:25,842-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:26,193-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:26,342-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:26,342-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:26,693-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:26,842-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:26,842-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:27,193-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:27,342-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:27,342-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:27,693-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:27,842-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:27,843-0500 INFO  ThrottleManager mem=143.59 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:28,142-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:28,193-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:28,337-0500 INFO  PerformanceDiagnosticInputStream [IN] Total transferred: 0 B, current rate: 0 B/s, average rate: 0 B/s
2014-05-06 17:29:28,337-0500 INFO  PerformanceDiagnosticInputStream [MEM] Heap total: 724.56 MB, Heap used: 143.9 MB
2014-05-06 17:29:28,343-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:28,343-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:28,693-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:28,843-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:28,843-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:28,843-0500 INFO  Buffers O allocated buffers: {} (0)
2014-05-06 17:29:29,162-0500 INFO  RuntimeStats$ProgressTicker   Active:1
2014-05-06 17:29:29,194-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:29,194-0500 INFO  Buffers I allocated buffers: {} (0)
2014-05-06 17:29:29,343-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:29,343-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:29,694-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:29,843-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:29,844-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:30,194-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:30,344-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:30,344-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:30,694-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:30,844-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:30,844-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:31,194-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:31,344-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:31,344-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:31,695-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:31,844-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:31,845-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:32,195-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:32,345-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:32,345-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:32,695-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:32,845-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:32,845-0500 INFO  ThrottleManager mem=143.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:33,195-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:33,280-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:33,345-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:33,345-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:33,695-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:33,846-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:33,846-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:34,195-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:34,346-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:34,346-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:34,696-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:34,846-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:34,846-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:35,196-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:35,346-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:35,347-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:35,696-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:35,847-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:35,847-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:36,196-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:36,347-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:36,347-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:36,696-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:36,847-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:36,847-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:37,197-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:37,243-0500 INFO  HeartBeatCommand TCPChannel [type: server, contact: 0506-2705590-000000-000000] up latency: 123ms, rtt: 152ms
2014-05-06 17:29:37,348-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:37,348-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:37,697-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:37,848-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:37,848-0500 INFO  ThrottleManager mem=144.06 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:38,197-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:38,338-0500 INFO  PerformanceDiagnosticInputStream [IN] Total transferred: 0 B, current rate: 0 B/s, average rate: 0 B/s
2014-05-06 17:29:38,338-0500 INFO  PerformanceDiagnosticInputStream [MEM] Heap total: 724.56 MB, Heap used: 144.24 MB
2014-05-06 17:29:38,348-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:38,348-0500 INFO  ThrottleManager mem=144.24 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:38,420-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:38,697-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:38,849-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:38,849-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:38,849-0500 INFO  Buffers O allocated buffers: {} (0)
2014-05-06 17:29:39,197-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:39,197-0500 INFO  Buffers I allocated buffers: {} (0)
2014-05-06 17:29:39,349-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:39,349-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:39,698-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:39,849-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:39,849-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:40,198-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:40,349-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:40,349-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:40,698-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:40,850-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:40,850-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:41,198-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:41,350-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:41,350-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:41,698-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:41,850-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:41,850-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:42,198-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:42,350-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:42,351-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:42,699-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:42,851-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:42,851-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:43,199-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:43,351-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:43,351-0500 INFO  ThrottleManager mem=144.54 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:43,561-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:43,699-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:43,851-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:43,851-0500 INFO  ThrottleManager mem=144.7 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:44,199-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:44,351-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:44,352-0500 INFO  ThrottleManager mem=144.7 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:44,700-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:44,852-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:44,852-0500 INFO  ThrottleManager mem=144.7 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:45,200-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:45,352-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:45,352-0500 INFO  ThrottleManager mem=144.7 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:45,700-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:45,852-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:45,852-0500 INFO  ThrottleManager mem=144.7 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:46,200-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:46,352-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:46,353-0500 INFO  ThrottleManager mem=144.7 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:46,700-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:46,853-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:46,853-0500 INFO  ThrottleManager mem=144.7 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:47,200-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:47,353-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:47,353-0500 INFO  ThrottleManager mem=144.85 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:47,701-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:47,853-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:47,853-0500 INFO  ThrottleManager mem=144.85 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:48,201-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:48,337-0500 INFO  PerformanceDiagnosticInputStream [IN] Total transferred: 0 B, current rate: 0 B/s, average rate: 0 B/s
2014-05-06 17:29:48,337-0500 INFO  PerformanceDiagnosticInputStream [MEM] Heap total: 724.56 MB, Heap used: 144.85 MB
2014-05-06 17:29:48,354-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:48,354-0500 INFO  ThrottleManager mem=144.85 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:48,699-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:48,701-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:48,854-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:48,854-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:48,854-0500 INFO  Buffers O allocated buffers: {} (0)
2014-05-06 17:29:49,201-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:49,201-0500 INFO  Buffers I allocated buffers: {} (0)
2014-05-06 17:29:49,354-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:49,354-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:49,701-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:49,854-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:49,854-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:50,201-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:50,355-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:50,355-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:50,702-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:50,855-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:50,855-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:51,202-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:51,355-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:51,355-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:51,702-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:51,855-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:51,855-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:52,202-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:52,356-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:52,356-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:52,702-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:52,856-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:52,856-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:53,203-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:53,356-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:53,356-0500 INFO  ThrottleManager mem=145.16 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:53,703-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:53,839-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:53,856-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:53,857-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:54,203-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:54,357-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:54,357-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:54,703-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:54,857-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:54,857-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:55,203-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:55,357-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:55,357-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:55,704-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:55,857-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:55,858-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:56,204-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:56,358-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:56,358-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:56,704-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:56,858-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:56,858-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:57,204-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:57,358-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:57,358-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:57,704-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:57,859-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:57,859-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:58,204-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:58,337-0500 INFO  PerformanceDiagnosticInputStream [IN] Total transferred: 0 B, current rate: 0 B/s, average rate: 0 B/s
2014-05-06 17:29:58,337-0500 INFO  PerformanceDiagnosticInputStream [MEM] Heap total: 724.56 MB, Heap used: 145.32 MB
2014-05-06 17:29:58,359-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:58,359-0500 INFO  ThrottleManager mem=145.32 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:58,705-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:58,859-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:58,859-0500 INFO  ThrottleManager mem=145.48 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:58,859-0500 INFO  Buffers O allocated buffers: {} (0)
2014-05-06 17:29:58,978-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:29:59,163-0500 INFO  RuntimeStats$ProgressTicker   Active:1
2014-05-06 17:29:59,205-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:59,205-0500 INFO  Buffers I allocated buffers: {} (0)
2014-05-06 17:29:59,359-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:59,360-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:29:59,705-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:59,860-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:29:59,860-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:00,205-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:00,360-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:00,360-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:00,705-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:00,860-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:00,860-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:01,206-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:01,360-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:01,361-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:01,706-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:01,861-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:01,861-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:02,206-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:02,361-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:02,361-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:02,706-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:02,861-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:02,862-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:03,207-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:03,362-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:03,362-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:03,707-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:03,862-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:03,862-0500 INFO  ThrottleManager mem=145.63 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:04,118-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:30:04,207-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:04,362-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:04,362-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:04,707-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:04,862-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:04,862-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:05,207-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:05,363-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:05,363-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:05,708-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:05,863-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:05,863-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:06,208-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:06,363-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:06,363-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:06,708-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:06,863-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:06,864-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:07,208-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:07,364-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:07,364-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:07,708-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:07,864-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:07,864-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:08,209-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:08,338-0500 INFO  PerformanceDiagnosticInputStream [IN] Total transferred: 0 B, current rate: 0 B/s, average rate: 0 B/s
2014-05-06 17:30:08,338-0500 INFO  PerformanceDiagnosticInputStream [MEM] Heap total: 724.56 MB, Heap used: 145.79 MB
2014-05-06 17:30:08,364-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:08,364-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:08,709-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:08,864-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:08,865-0500 INFO  ThrottleManager mem=145.79 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:08,865-0500 INFO  Buffers O allocated buffers: {} (0)
2014-05-06 17:30:09,209-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:09,209-0500 INFO  Buffers I allocated buffers: {} (0)
2014-05-06 17:30:09,257-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:30:09,365-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:09,365-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:09,709-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:09,865-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:09,865-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:10,209-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:10,365-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:10,365-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:10,533-0500 INFO  HeartBeatCommand TCPChannel [type: server, contact: 0506-2705590-000000-000000] up latency: 123ms, rtt: 152ms
2014-05-06 17:30:10,710-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:10,865-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:10,866-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:11,210-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:11,366-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:11,366-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:11,710-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:11,866-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:11,866-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:12,210-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:12,366-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:12,366-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:12,710-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:12,866-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:12,867-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:13,210-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:13,367-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:13,367-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:13,711-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:13,867-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:13,867-0500 INFO  ThrottleManager mem=146.1 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:14,211-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:14,367-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:14,367-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:14,394-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:30:14,711-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:14,868-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:14,868-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:15,211-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:15,368-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:15,368-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:15,711-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:15,868-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:15,868-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:16,212-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:16,368-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:16,368-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:16,712-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:16,869-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:16,869-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:17,212-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:17,369-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:17,369-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:17,712-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:17,869-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:17,869-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:18,212-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:18,337-0500 INFO  PerformanceDiagnosticInputStream [IN] Total transferred: 0 B, current rate: 0 B/s, average rate: 0 B/s
2014-05-06 17:30:18,337-0500 INFO  PerformanceDiagnosticInputStream [MEM] Heap total: 724.56 MB, Heap used: 146.41 MB
2014-05-06 17:30:18,369-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:18,370-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:18,712-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:18,870-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:18,870-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:18,870-0500 INFO  Buffers O allocated buffers: {} (0)
2014-05-06 17:30:19,213-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:19,213-0500 INFO  Buffers I allocated buffers: {} (0)
2014-05-06 17:30:19,370-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:19,370-0500 INFO  ThrottleManager mem=146.41 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:19,532-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:30:19,713-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:19,870-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:19,870-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:20,213-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:20,371-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:20,371-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:20,713-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:20,871-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:20,871-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:21,213-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:21,371-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:21,371-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:21,714-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:21,871-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:21,871-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:22,214-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:22,372-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:22,372-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:22,714-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:22,872-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:22,872-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:23,214-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:23,372-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:23,372-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:23,714-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:23,872-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:23,872-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:24,215-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:24,373-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:24,373-0500 INFO  ThrottleManager mem=146.74 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:24,671-0500 INFO  AbstractQueuePoller Actively monitored: 1, New: 0, Done: 0
2014-05-06 17:30:24,715-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:24,873-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:24,873-0500 INFO  ThrottleManager mem=146.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:25,215-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:25,373-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:25,373-0500 INFO  ThrottleManager mem=146.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:25,715-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:25,873-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:25,873-0500 INFO  ThrottleManager mem=146.9 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:26,215-0500 INFO  ThrottleManager I maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:26,374-0500 INFO  ThrottleManager O maxBuffers=1024, crtBuffers=0, allowedTransfers=256, active=0, suspended=0
2014-05-06 17:30:26,374-0500 INFO  ThrottleManager mem=147.05 MB, heap=724.56 MB, maxHeap=7.11 GB
2014-05-06 17:30:26,561-0500 DEBUG Cpu Stageout workerid=000000
2014-05-06 17:30:26,561-0500 INFO  RequestHandler Handler(tag: 6647, JOBSTATUS) unregistering (send)
2014-05-06 17:30:26,561-0500 INFO  RuntimeStats$ProgressTicker   Stage out:1
2014-05-06 17:30:26,561-0500 INFO  RequestHandler Handler(tag: 16, JOBSTATUS) unregistering (send)
2014-05-06 17:30:26,562-0500 INFO  PutFileHandler Handler(tag: 6648, PUT) source: ./df-20140506-1727-39v1is9b/jobs/n/bash-nxdye9ql/./1goo/f0001b.txt.err
2014-05-06 17:30:26,562-0500 INFO  PutFileHandler Handler(tag: 6648, PUT) destination: proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//home/wcatino/df/././1goo/f0001b.txt.err
2014-05-06 17:30:26,564-0500 INFO  PutFileCommand Sending Command(tag: 17, PUT) (t) on cpipe://1
2014-05-06 17:30:26,564-0500 INFO  PutFileCommand Command(tag: 17, PUT) (t) sending data
2014-05-06 17:30:26,564-0500 INFO  PutFileHandler Handler(tag: 6648, PUT) -> 17
2014-05-06 17:30:26,564-0500 INFO  PutFileHandler Handler(tag: 17, PUT) source: ./df-20140506-1727-39v1is9b/jobs/n/bash-nxdye9ql/./1goo/f0001b.txt.err
2014-05-06 17:30:26,564-0500 INFO  PutFileHandler Handler(tag: 17, PUT) destination: file://localhost//home/wcatino/df/./1goo/f0001b.txt.err
2014-05-06 17:30:26,712-0500 INFO  PutFileHandler Handler(tag: 17, PUT) Transfer done
2014-05-06 17:30:26,712-0500 INFO  RequestHandler Handler(tag: 17, PUT) unregistering (send)
2014-05-06 17:30:26,712-0500 DEBUG Cpu Stageout workerid=000000
2014-05-06 17:30:26,712-0500 INFO  PutFileHandler Handler(tag: 6648, PUT) Transfer done
2014-05-06 17:30:26,712-0500 INFO  RequestHandler Handler(tag: 18, JOBSTATUS) unregistering (send)
2014-05-06 17:30:26,712-0500 INFO  RequestHandler Handler(tag: 6649, JOBSTATUS) unregistering (send)
2014-05-06 17:30:26,712-0500 INFO  RequestHandler Handler(tag: 6648, PUT) unregistering (send)
2014-05-06 17:30:26,712-0500 INFO  PutFileHandler Handler(tag: 6650, PUT) source: ./df-20140506-1727-39v1is9b/jobs/n/bash-nxdye9ql/./1goo/f0001b.txt.csv
2014-05-06 17:30:26,712-0500 INFO  PutFileHandler Handler(tag: 6650, PUT) destination: proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//home/wcatino/df/././1goo/f0001b.txt.csv
2014-05-06 17:30:26,712-0500 INFO  PutFileCommand Sending Command(tag: 19, PUT) (t) on cpipe://1
2014-05-06 17:30:26,712-0500 INFO  PutFileCommand Command(tag: 19, PUT) (t) sending data
2014-05-06 17:30:26,712-0500 INFO  PutFileHandler Handler(tag: 6650, PUT) -> 19
2014-05-06 17:30:26,712-0500 INFO  PutFileHandler Handler(tag: 19, PUT) source: ./df-20140506-1727-39v1is9b/jobs/n/bash-nxdye9ql/./1goo/f0001b.txt.csv
2014-05-06 17:30:26,712-0500 INFO  PutFileHandler Handler(tag: 19, PUT) destination: file://localhost//home/wcatino/df/./1goo/f0001b.txt.csv
2014-05-06 17:30:26,713-0500 INFO  PutFileHandler Handler(tag: 19, PUT) Transfer done
2014-05-06 17:30:26,713-0500 INFO  RequestHandler Handler(tag: 19, PUT) unregistering (send)
2014-05-06 17:30:26,713-0500 INFO  PutFileHandler Handler(tag: 6650, PUT) Transfer done
2014-05-06 17:30:26,713-0500 INFO  RequestHandler Handler(tag: 6650, PUT) unregistering (send)
2014-05-06 17:30:26,713-0500 DEBUG Cpu Stageout workerid=000000
2014-05-06 17:30:26,713-0500 INFO  RequestHandler Handler(tag: 20, JOBSTATUS) unregistering (send)
2014-05-06 17:30:26,713-0500 INFO  RequestHandler Handler(tag: 6651, JOBSTATUS) unregistering (send)
2014-05-06 17:30:26,714-0500 INFO  PutFileHandler Handler(tag: 6652, PUT) source: ./df-20140506-1727-39v1is9b/jobs/n/bash-nxdye9ql/./1goo/f0001b.txt.out
2014-05-06 17:30:26,714-0500 INFO  PutFileHandler Handler(tag: 6652, PUT) destination: proxy://u749f0d69-145d3a68ebd--7fff-u749f0d69-145d3a68ebd--8000S//home/wcatino/df/././1goo/f0001b.txt.out
2014-05-06 17:30:26,714-0500 INFO  PutFileCommand Sending Command(tag: 21, PUT) (t) on cpipe://1
2014-05-06 17:30:26,714-0500 INFO  PutFileCommand Command(tag: 21, PUT) (t) sending data
2014-05-06 17:30:26,714-0500 INFO  PutFileHandler Handler(tag: 6652, PUT) -> 21
2014-05-06 17:30:26,714-0500 INFO  PutFileHandler Handler(tag: 21, PUT) source: ./df-20140506-1727-39v1is9b/jobs/n/bash-nxdye9ql/./1goo/f0001b.txt.out
2014-05-06 17:30:26,714-0500 INFO  PutFileHandler Handler(tag: 21, PUT) destination: file://localhost//home/wcatino/df/./1goo/f0001b.txt.out
2014-05-06 17:30:26,714-0500 INFO  PutFileHandler Handler(tag: 21, PUT) Transfer done
2014-05-06 17:30:26,714-0500 INFO  RequestHandler Handler(tag: 21, PUT) unregistering (send)
2014-05-06 17:30:26,714-0500 INFO  PutFileHandler Handler(tag: 6652, PUT) Transfer done
2014-05-06 17:30:26,714-0500 INFO  RequestHandler Handler(tag: 6652, PUT) unregistering (send)
2014-05-06 17:30:26,866-0500 DEBUG Cpu Completed
2014-05-06 17:30:26,866-0500 INFO  Cpu 0506-2705590-000000:0 jobTerminated
2014-05-06 17:30:26,866-0500 DEBUG Cpu ready for work: block=0506-2705590-000000 id=0
2014-05-06 17:30:26,866-0500 INFO  LateBindingScheduler jobs queued: 0
2014-05-06 17:30:26,866-0500 INFO  RequestHandler Handler(tag: 6653, JOBSTATUS) unregistering (send)
2014-05-06 17:30:26,866-0500 DEBUG Cpu requesting work: block=0506-2705590-000000 id=0 Cpus sleeping: 1
2014-05-06 17:30:26,866-0500 DEBUG Cpu 0506-2705590-000000:0 sleeping
2014-05-06 17:30:26,867-0500 INFO  RequestHandler Handler(tag: 22, JOBSTATUS) unregistering (send)
2014-05-06 17:30:26,868-0500 DEBUG swift JOB_END jobid=bash-nxdye9ql
2014-05-06 17:30:26,868-0500 INFO  swift END_SUCCESS thread=0-2-0-4 tr=bash
2014-05-06 17:30:26,869-0500 DEBUG swift PROCEDURE_END line=5 thread=0-2-0-4 name=wrapper
2014-05-06 17:30:26,869-0500 INFO  CleanDataset Cleaning df:file - Closed
2014-05-06 17:30:26,870-0500 INFO  CleanDataset Cleaning all_files:file[int] - Closed
2014-05-06 17:30:26,870-0500 INFO  CleanDataset Cleaning names:string[int] - Closed
2014-05-06 17:30:26,870-0500 INFO  CleanDataset Cleaning err:file - Closed
2014-05-06 17:30:26,870-0500 INFO  CleanDataset Cleaning out:file - Closed
2014-05-06 17:30:26,870-0500 DEBUG swift FOREACH_IT_END line=18 thread=0-2-0
2014-05-06 17:30:26,870-0500 INFO  RuntimeStats$ProgressTicker   Finished successfully:1
2014-05-06 17:30:26,878-0500 DEBUG swift Starting cleanups
2014-05-06 17:30:26,879-0500 INFO  swift START cleanups=[]
2014-05-06 17:30:26,879-0500 DEBUG swift Ending cleanups
2014-05-06 17:30:26,880-0500 INFO  CleanDataset Cleaning wrap:script - Closed
2014-05-06 17:30:26,880-0500 INFO  CleanDataset Cleaning calc_df:script - Closed
2014-05-06 17:30:26,880-0500 INFO  CleanDataset Cleaning all_docs:file[int] - Closed
2014-05-06 17:30:26,882-0500 INFO  Loader Swift finished with no errors
2014-05-06 17:30:26,883-0500 INFO  ServiceManager Cleaning up...
2014-05-06 17:30:26,883-0500 INFO  ServiceManager Shutting down service at https://192.170.227.195:40798
2014-05-06 17:30:26,884-0500 INFO  RequestHandler Handler(tag: 3, SHUTDOWNSERVICE) unregistering (send)
2014-05-06 17:30:26,984-0500 INFO  ServiceShutdownHandler Shutdown command received
2014-05-06 17:30:26,985-0500 INFO  RequestHandler Handler(tag: 23, UNREGISTER) unregistering (send)
2014-05-06 17:30:26,987-0500 INFO  BlockQueueProcessor Shutting down blocks
2014-05-06 17:30:26,988-0500 INFO  Block Shutting down block Block 0506-2705590-000000 (1x14340.000s)
2014-05-06 17:30:26,988-0500 INFO  RemoteLogHandler BLOCK_SHUTDOWN id=0506-2705590-000000
2014-05-06 17:30:26,988-0500 INFO  RequestHandler Handler(tag: 24, RLOG) unregistering (send)
2014-05-06 17:30:26,989-0500 INFO  Block Adding short shutdown watchdog: count = 1, workers = 1, now = true
2014-05-06 17:30:26,989-0500 INFO  Block Average utilization: 99.99%
2014-05-06 17:30:26,989-0500 INFO  CoasterService Shutdown sequence completed
2014-05-06 17:30:26,989-0500 INFO  RemoteLogHandler BLOCK_UTILIZATION id=0506-2705590-000000, u=99.99
2014-05-06 17:30:26,989-0500 INFO  RequestHandler Handler(tag: 25, RLOG) unregistering (send)