2012-11-20 10:48:46,871-0800 DEBUG Loader arguments: [-tc.file, tc.data, -logfile, bleh.log, -pgraph, graph.dot, simpleMapReduce.swift] 2012-11-20 10:48:46,871-0800 DEBUG Loader Max heap: 238616576 2012-11-20 10:48:46,874-0800 DEBUG textfiles BEGIN SWIFTSCRIPT: // SIMPLEMAPREDUCE // An exercise in extremely complex user-friendly parallel scripting // swift simpleMapReduce.swift -in=IN -out=OUT -dim=DIM // runs this script with input file IN, output file OUT and splitting dimension // DIM. //////////////////////////////////////////////////////////////////////////////// // TYPES TYPES TYPES TYPES TYPES TYPES TYPES TYPES TYPES TYPES TYPES// //////////////////////////////////////////////////////////////////////////////// type RSFile; // rsf file type StringFile; // File that stores strings //////////////////////////////////////////////////////////////////////////////// // APP APP APP APP APP APP APP APP APP APP APP APP APP APP APP // //////////////////////////////////////////////////////////////////////////////// // getNDims: Extract last dimension from rsf file app (StringFile ndims) appGetNDims(RSFile input) { sffiledims_script @filename(input) "1" stdout=@filename(ndims); } // getDims: Extract dimension list from rsf file app (StringFile dims) appGetDims(RSFile input) { sffiledims_script @filename(input) "2" stdout=@filename(dims); } // getWindow: Window a slice from rsf file app (RSFile out) appSplitFile(RSFile inp, string dim, int slice) { sfwindow_script @filename(inp) @filename(out) dim slice; } // addFiles: adds inp1 and inp2 and returns out app (RSFile out) appAddFiles(RSFile inp1, RSFile inp2) { sfadd_script @filename(out) @filename(inp1) @filename(inp2); } //////////////////////////////////////////////////////////////////////////////// // PROCEDURES PROCEDURES PROCEDURES PROCEDURES PROCEDURES PROCEDURES ///// //////////////////////////////////////////////////////////////////////////////// //////////////////////////////////////////////////////////////////////////////// // VARIABLES VARIABLES VARIABLES VARIABLES VARIABLES VARIABLES VARIABLES// //////////////////////////////////////////////////////////////////////////////// // In-core variables string input_name; // input name of the file string output_name; // output name of the file string last_dim; // Last dimension of file (default splitting dimension) string split_dim; // Splitting dimension string dims_list; // string of dimensions (unsplitted) string dims_array[]; // Array of string of dimensions (splitted) int dim_length; // length of splitted dimension // File variables // Setup input and output files RSFile input_data ; RSFile output_data ; StringFile ndims_file; // number of dimensions of the input file StringFile dims_file; // dimension array of the input file RSFile input_chunks[];// ; // Splitted input RSFile processed_chunks[];// ; // data chunks after parallel processing RSFile output_chunks[];// ; // Temporary output array for reduction //////////////////////////////////////////////////////////////////////////////// // MAIN MAIN MAIN MAIN MAIN MAIN MAIN MAIN MAIN MAIN MAIN MAIN ///// //////////////////////////////////////////////////////////////////////////////// // Define and parse input arguments input_name = @arg("in","in.rsf"); output_name = @arg("out","out.rsf"); // extract dims and setup variables ndims_file = appGetNDims(input_data); dims_file = appGetDims(input_data); // Define and parse split dimension and dimensions array last_dim = readData(ndims_file); split_dim = @arg("dim", last_dim); dims_list = readData(dims_file); dims_array = @strsplit(dims_list,","); dim_length = @toint(dims_array[@toint(split_dim)-1]); trace("Dim length = ", dim_length); // Split the files parallelly foreach i in [0:dim_length-1] { trace("Splitting ", i); input_chunks[i] = appSplitFile(input_data, split_dim, i+1); trace("Working furiously on ", @filename(input_chunks[i])); trace("Chunk number: ", i); processed_chunks[i] = input_chunks[i]; } // Process the files parallelly //foreach file_chunk, i in input_chunks { // trace("Working furiously on ", @filename(file_chunk)); // trace("Chunk number: ", i); // processed_chunks[i] = file_chunk; //} // Add all the chunks together iterate i { if( i == 0 ) { trace("Setting chunk 0 to ", @filename(output_chunks[0])); output_chunks[0] = processed_chunks[0]; } else { trace("Adding ", i); output_chunks[i] = appAddFiles(processed_chunks[i], output_chunks[i-1]); } } until (i == dim_length-1); output_data = output_chunks[dim_length-1]; 2012-11-20 10:48:46,876-0800 DEBUG textfiles END SWIFTSCRIPT: 2012-11-20 10:48:46,898-0800 INFO Loader simpleMapReduce.swift: source file is new. Recompiling. 2012-11-20 10:48:46,907-0800 DEBUG Loader kmlversion is >fbcf024c-11be-4680-ad51-a8a02f86098d< 2012-11-20 10:48:46,907-0800 DEBUG Loader build version is >fbcf024c-11be-4680-ad51-a8a02f86098d< 2012-11-20 10:48:47,698-0800 INFO Karajan Validation of XML intermediate file was successful 2012-11-20 10:48:48,281-0800 DEBUG Loader setting: pgraph to: graph.dot 2012-11-20 10:48:48,281-0800 DEBUG Loader setting: tc.file to: tc.data 2012-11-20 10:48:48,282-0800 DEBUG textfiles using default sites file 2012-11-20 10:48:48,286-0800 INFO VDL2ExecutionContext Stack dump: Level 1 [iA = 0, iB = 0, bA = false, bB = false] vdl:instanceconfig = Swift configuration [] vdl:operation = run swift.home = /users/slic/tlai/work/swift-0.93/cog/modules/swift/dist/swift-svn/bin/.. PATH_SEPARATOR = / 2012-11-20 10:48:49,015-0800 INFO unknown Using sites file: /users/slic/tlai/work/swift-0.93/cog/modules/swift/dist/swift-svn/bin/../etc/sites.xml 2012-11-20 10:48:49,049-0800 INFO unknown Using tc.data: tc.data 2012-11-20 10:48:49,253-0800 INFO AbstractScheduler Setting resources to: {localhost=localhost} 2012-11-20 10:48:49,884-0800 INFO unknown Swift 0.93 swift-r5997 cog-r3497 2012-11-20 10:48:49,885-0800 INFO unknown RUNID id=run:20121120-1048-lvoc0qx9 2012-11-20 10:48:50,007-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-4 name=readData 2012-11-20 10:48:50,008-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-9 name=trace 2012-11-20 10:48:50,007-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-6 name=readData 2012-11-20 10:48:50,015-0800 INFO VDLFunction FUNCTION: arg() 2012-11-20 10:48:50,015-0800 INFO VDLFunction FUNCTION: arg() 2012-11-20 10:48:50,015-0800 INFO SetFieldValue Set: input_name=in.rsf 2012-11-20 10:48:50,016-0800 INFO SetFieldValue Set: output_name=out.rsf 2012-11-20 10:48:50,018-0800 DEBUG vdl:mains SCOPE thread=0-11-0-1 2012-11-20 10:48:50,018-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-11-0-1-0 name=trace 2012-11-20 10:48:50,021-0800 INFO RootDataNode Found data input_data:RSFile - Closed.$ 2012-11-20 10:48:50,023-0800 INFO SetFieldValue Set: output_chunks[0]=null 2012-11-20 10:48:50,025-0800 DEBUG appgetdims PROCEDURE line=22 thread=0-3 name=appGetDims 2012-11-20 10:48:50,026-0800 DEBUG appgetndims PROCEDURE line=17 thread=0-2 name=appGetNDims 2012-11-20 10:48:50,031-0800 WARN trace SwiftScript trace: Setting chunk 0 to , _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-0 2012-11-20 10:48:50,031-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-11-0-1-0 2012-11-20 10:48:50,041-0800 INFO vdl:execute START thread=0-3 tr=sffiledims_script 2012-11-20 10:48:50,045-0800 INFO vdl:execute START thread=0-2 tr=sffiledims_script 2012-11-20 10:48:50,064-0800 INFO WeightedHostScoreScheduler CONTACT_SELECTED host=localhost, score=1.000 2012-11-20 10:48:50,066-0800 INFO GlobalSubmitQueue No global submit throttle set. Using default (1024) 2012-11-20 10:48:50,068-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,080-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,082-0800 INFO vdl:initshareddir START host=localhost - Initializing shared directory 2012-11-20 10:48:50,096-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,127-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,134-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,136-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,137-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,140-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,141-0800 INFO vdl:initshareddir END host=localhost - Done initializing shared directory 2012-11-20 10:48:50,143-0800 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=sffiledims_script-trdq091l thread=0-3-1 host=localhost replicationGroup=rrdq091l 2012-11-20 10:48:50,148-0800 INFO vdl:createdirset START jobid=sffiledims_script-trdq091l host=localhost - Initializing directory structure 2012-11-20 10:48:50,149-0800 INFO vdl:createdirs START path=_concurrent dir=simpleMapReduce-20121120-1048-lvoc0qx9/shared - Creating directory structure 2012-11-20 10:48:50,151-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,151-0800 INFO vdl:createdirset END jobid=sffiledims_script-trdq091l - Done initializing directory structure 2012-11-20 10:48:50,152-0800 INFO vdl:dostagein START jobid=sffiledims_script-trdq091l - Staging in files 2012-11-20 10:48:50,159-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,163-0800 DEBUG vdl:dostagein CDM: file://localhost/in.rsf : DEFAULT 2012-11-20 10:48:50,168-0800 DEBUG vdl:dostageinfile FILE_STAGE_IN_START file=in.rsf srchost=localhost srcdir= srcname=in.rsf desthost=localhost destdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/ provider=file policy=DEFAULT 2012-11-20 10:48:50,179-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,180-0800 DEBUG vdl:dostageinfile FILE_STAGE_IN_END file=in.rsf srchost=localhost srcdir= srcname=in.rsf desthost=localhost destdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/ provider=file 2012-11-20 10:48:50,181-0800 INFO vdl:dostagein END jobid=sffiledims_script-trdq091l - Staging in finished 2012-11-20 10:48:50,182-0800 DEBUG vdl:execute2 JOB_START jobid=sffiledims_script-trdq091l tr=sffiledims_script arguments=[in.rsf, 2] tmpdir=simpleMapReduce-20121120-1048-lvoc0qx9/jobs/t/sffiledims_script-trdq091l host=localhost 2012-11-20 10:48:50,187-0800 DEBUG textfiles BEGIN TC: localhost sffiledims_script ~/work/mapReduceScripts/bin/sffiledims_script INSTALLED INTEL32::LINUX null localhost sfwindow_script ~/work/mapReduceScripts/bin/sfwindow_script INSTALLED INTEL32::LINUX null localhost funHandle_script ~/work/mapReduceScripts/bin/funHandle_script INSTALLED INTEL32::LINUX null localhost sfadd_script ~/work/mapReduceScripts/bin/sfadd_script INSTALLED INTEL32::LINUX null localhost echo /bin/echo INSTALLED INTEL32::LINUX null localhost cat_script ~/work/mapReduceScripts/bin/cat_script INSTALLED INTEL32::LINUX null 2012-11-20 10:48:50,187-0800 DEBUG textfiles END TC: 2012-11-20 10:48:50,198-0800 INFO GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-3-1-1353437329051) is /bin/bash shared/_swiftwrap sffiledims_script-trdq091l -jobdir t -scratch -e ~/work/mapReduceScripts/bin/sffiledims_script -out _concurrent/dims_file-e44445eb-08c4-4598-9d76-0450e31de7ab- -err stderr.txt -i -d _concurrent -if in.rsf -of _concurrent/dims_file-e44445eb-08c4-4598-9d76-0450e31de7ab- -k -cdmfile -status files -a in.rsf 2 2012-11-20 10:48:50,206-0800 INFO JobSubmissionTaskHandler Submit: in: /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9 command: /bin/bash /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9/shared/_swiftwrap sffiledims_script-trdq091l -jobdir t -scratch -e ~/work/mapReduceScripts/bin/sffiledims_script -out _concurrent/dims_file-e44445eb-08c4-4598-9d76-0450e31de7ab- -err stderr.txt -i -d _concurrent -if in.rsf -of _concurrent/dims_file-e44445eb-08c4-4598-9d76-0450e31de7ab- -k -cdmfile -status files -a in.rsf 2 2012-11-20 10:48:50,575-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,578-0800 DEBUG vdl:checkjobstatus START jobid=sffiledims_script-trdq091l 2012-11-20 10:48:50,580-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,581-0800 INFO vdl:checkjobstatus SUCCESS jobid=sffiledims_script-trdq091l - Success file found 2012-11-20 10:48:50,582-0800 DEBUG vdl:execute2 STAGING_OUT jobid=sffiledims_script-trdq091l 2012-11-20 10:48:50,583-0800 INFO vdl:dostageout START jobid=sffiledims_script-trdq091l - Staging out files 2012-11-20 10:48:50,583-0800 DEBUG vdl:dostageout stageouts: [[$, dims_file:StringFile - Open]] 2012-11-20 10:48:50,588-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_START srcname=dims_file-e44445eb-08c4-4598-9d76-0450e31de7ab- srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent srchost=localhost destdir=_concurrent desthost=localhost provider=file 2012-11-20 10:48:50,595-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,612-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,613-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_END srcname=dims_file-e44445eb-08c4-4598-9d76-0450e31de7ab- srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent srchost=localhost destdir=_concurrent desthost=localhost provider=file 2012-11-20 10:48:50,614-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:50,618-0800 INFO vdl:dostageout END jobid=sffiledims_script-trdq091l - Staging out finished 2012-11-20 10:48:50,620-0800 DEBUG vdl:execute2 JOB_END jobid=sffiledims_script-trdq091l 2012-11-20 10:48:50,621-0800 INFO vdl:execute END_SUCCESS thread=0-3 tr=sffiledims_script 2012-11-20 10:48:50,622-0800 DEBUG appgetdims PROCEDURE_END line=22 2012-11-20 10:48:50,623-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-6 2012-11-20 10:48:50,624-0800 INFO VDLFunction FUNCTION: strsplit() 2012-11-20 10:48:50,624-0800 INFO SetFieldValue Set: dims_array={2=3, 1=4, 0=5} 2012-11-20 10:48:51,118-0800 INFO WeightedHostScoreScheduler CONTACT_SELECTED host=localhost, score=1.995 2012-11-20 10:48:51,123-0800 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=sffiledims_script-urdq091l thread=0-2-1 host=localhost replicationGroup=srdq091l 2012-11-20 10:48:51,129-0800 INFO vdl:createdirset START jobid=sffiledims_script-urdq091l host=localhost - Initializing directory structure 2012-11-20 10:48:51,130-0800 INFO vdl:createdirset END jobid=sffiledims_script-urdq091l - Done initializing directory structure 2012-11-20 10:48:51,131-0800 INFO vdl:dostagein START jobid=sffiledims_script-urdq091l - Staging in files 2012-11-20 10:48:51,134-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:51,135-0800 DEBUG vdl:dostagein CDM: file://localhost/in.rsf : DEFAULT 2012-11-20 10:48:51,137-0800 INFO vdl:dostagein END jobid=sffiledims_script-urdq091l - Staging in finished 2012-11-20 10:48:51,138-0800 DEBUG vdl:execute2 JOB_START jobid=sffiledims_script-urdq091l tr=sffiledims_script arguments=[in.rsf, 1] tmpdir=simpleMapReduce-20121120-1048-lvoc0qx9/jobs/u/sffiledims_script-urdq091l host=localhost 2012-11-20 10:48:51,145-0800 INFO GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-2-1-1353437329064) is /bin/bash shared/_swiftwrap sffiledims_script-urdq091l -jobdir u -scratch -e ~/work/mapReduceScripts/bin/sffiledims_script -out _concurrent/ndims_file-fddfd44b-6b93-4c19-ac4e-bc2de62169cb- -err stderr.txt -i -d _concurrent -if in.rsf -of _concurrent/ndims_file-fddfd44b-6b93-4c19-ac4e-bc2de62169cb- -k -cdmfile -status files -a in.rsf 1 2012-11-20 10:48:51,145-0800 INFO JobSubmissionTaskHandler Submit: in: /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9 command: /bin/bash /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9/shared/_swiftwrap sffiledims_script-urdq091l -jobdir u -scratch -e ~/work/mapReduceScripts/bin/sffiledims_script -out _concurrent/ndims_file-fddfd44b-6b93-4c19-ac4e-bc2de62169cb- -err stderr.txt -i -d _concurrent -if in.rsf -of _concurrent/ndims_file-fddfd44b-6b93-4c19-ac4e-bc2de62169cb- -k -cdmfile -status files -a in.rsf 1 2012-11-20 10:48:51,379-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:51,382-0800 DEBUG vdl:checkjobstatus START jobid=sffiledims_script-urdq091l 2012-11-20 10:48:51,383-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:51,384-0800 INFO vdl:checkjobstatus SUCCESS jobid=sffiledims_script-urdq091l - Success file found 2012-11-20 10:48:51,384-0800 DEBUG vdl:execute2 STAGING_OUT jobid=sffiledims_script-urdq091l 2012-11-20 10:48:51,385-0800 INFO vdl:dostageout START jobid=sffiledims_script-urdq091l - Staging out files 2012-11-20 10:48:51,385-0800 DEBUG vdl:dostageout stageouts: [[$, ndims_file:StringFile - Open]] 2012-11-20 10:48:51,389-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_START srcname=ndims_file-fddfd44b-6b93-4c19-ac4e-bc2de62169cb- srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent srchost=localhost destdir=_concurrent desthost=localhost provider=file 2012-11-20 10:48:51,391-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:51,397-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:51,397-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_END srcname=ndims_file-fddfd44b-6b93-4c19-ac4e-bc2de62169cb- srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent srchost=localhost destdir=_concurrent desthost=localhost provider=file 2012-11-20 10:48:51,399-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:51,401-0800 INFO vdl:dostageout END jobid=sffiledims_script-urdq091l - Staging out finished 2012-11-20 10:48:51,403-0800 DEBUG vdl:execute2 JOB_END jobid=sffiledims_script-urdq091l 2012-11-20 10:48:51,403-0800 INFO vdl:execute END_SUCCESS thread=0-2 tr=sffiledims_script 2012-11-20 10:48:51,405-0800 DEBUG appgetndims PROCEDURE_END line=17 2012-11-20 10:48:51,405-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-4 2012-11-20 10:48:51,406-0800 INFO VDLFunction FUNCTION: arg() 2012-11-20 10:48:51,406-0800 INFO SetFieldValue Set: split_dim=3 2012-11-20 10:48:51,407-0800 INFO VDLFunction FUNCTION: toint() 2012-11-20 10:48:51,408-0800 INFO VDLFunction FUNCTION: toint() 2012-11-20 10:48:51,408-0800 INFO SetFieldValue Set: dim_length=3.0 2012-11-20 10:48:51,409-0800 WARN trace SwiftScript trace: Dim length = , 3.0 2012-11-20 10:48:51,409-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-9 2012-11-20 10:48:51,410-0800 INFO SetFieldValue Set: output_data=null 2012-11-20 10:48:51,415-0800 DEBUG vdl:mains FOREACH_IT_START line=83 thread=0-10-0 2012-11-20 10:48:51,416-0800 DEBUG vdl:mains FOREACH_IT_START line=83 thread=0-10-1 2012-11-20 10:48:51,416-0800 DEBUG vdl:mains FOREACH_IT_START line=83 thread=0-10-2 2012-11-20 10:48:51,416-0800 DEBUG vdl:mains SCOPE thread=0-10-0 2012-11-20 10:48:51,416-0800 DEBUG vdl:mains SCOPE thread=0-10-1 2012-11-20 10:48:51,416-0800 DEBUG vdl:mains SCOPE thread=0-10-2 2012-11-20 10:48:51,417-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-0-0 name=trace 2012-11-20 10:48:51,417-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-0-2 name=trace 2012-11-20 10:48:51,417-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-0-3 name=trace 2012-11-20 10:48:51,421-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-1-0 name=trace 2012-11-20 10:48:51,421-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-1-2 name=trace 2012-11-20 10:48:51,421-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-1-3 name=trace 2012-11-20 10:48:51,421-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-2-0 name=trace 2012-11-20 10:48:51,422-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-2-2 name=trace 2012-11-20 10:48:51,422-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-10-2-3 name=trace 2012-11-20 10:48:51,422-0800 INFO SetFieldValue Set: processed_chunks[0]=null 2012-11-20 10:48:51,427-0800 WARN trace SwiftScript trace: Working furiously on , _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 2012-11-20 10:48:51,427-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-0-2 2012-11-20 10:48:51,428-0800 WARN trace SwiftScript trace: Chunk number: , 0.0 2012-11-20 10:48:51,429-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-0-3 2012-11-20 10:48:51,429-0800 WARN trace SwiftScript trace: Splitting , 0.0 2012-11-20 10:48:51,429-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-0-0 2012-11-20 10:48:51,430-0800 DEBUG appsplitfile PROCEDURE line=27 thread=0-10-0-1 name=appSplitFile 2012-11-20 10:48:51,433-0800 INFO SetFieldValue Set: processed_chunks[1]=null 2012-11-20 10:48:51,433-0800 INFO SetFieldValue Set: processed_chunks[2]=null 2012-11-20 10:48:51,435-0800 INFO vdl:execute START thread=0-10-0-1 tr=sfwindow_script 2012-11-20 10:48:51,436-0800 WARN trace SwiftScript trace: Splitting , 2.0 2012-11-20 10:48:51,436-0800 WARN trace SwiftScript trace: Working furiously on , _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2 2012-11-20 10:48:51,436-0800 WARN trace SwiftScript trace: Working furiously on , _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1 2012-11-20 10:48:51,437-0800 WARN trace SwiftScript trace: Chunk number: , 2.0 2012-11-20 10:48:51,437-0800 WARN trace SwiftScript trace: Chunk number: , 1.0 2012-11-20 10:48:51,437-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-2-2 2012-11-20 10:48:51,437-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-1-2 2012-11-20 10:48:51,438-0800 WARN trace SwiftScript trace: Splitting , 1.0 2012-11-20 10:48:51,437-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-2-0 2012-11-20 10:48:51,438-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-1-0 2012-11-20 10:48:51,438-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-1-3 2012-11-20 10:48:51,438-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-10-2-3 2012-11-20 10:48:51,439-0800 DEBUG appsplitfile PROCEDURE line=27 thread=0-10-2-1 name=appSplitFile 2012-11-20 10:48:51,440-0800 DEBUG appsplitfile PROCEDURE line=27 thread=0-10-1-1 name=appSplitFile 2012-11-20 10:48:51,441-0800 INFO WeightedHostScoreScheduler CONTACT_SELECTED host=localhost, score=2.481 2012-11-20 10:48:51,445-0800 INFO vdl:execute START thread=0-10-2-1 tr=sfwindow_script 2012-11-20 10:48:51,445-0800 INFO vdl:execute START thread=0-10-1-1 tr=sfwindow_script 2012-11-20 10:48:51,447-0800 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=sfwindow_script-yrdq091l thread=0-10-0-1-1 host=localhost replicationGroup=vrdq091l 2012-11-20 10:48:51,452-0800 INFO vdl:createdirset START jobid=sfwindow_script-yrdq091l host=localhost - Initializing directory structure 2012-11-20 10:48:51,452-0800 INFO vdl:createdirs START path=_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ dir=simpleMapReduce-20121120-1048-lvoc0qx9/shared - Creating directory structure 2012-11-20 10:48:51,453-0800 INFO LateBindingScheduler JobQueue: 2 2012-11-20 10:48:51,454-0800 INFO vdl:createdirset END jobid=sfwindow_script-yrdq091l - Done initializing directory structure 2012-11-20 10:48:51,454-0800 INFO vdl:dostagein START jobid=sfwindow_script-yrdq091l - Staging in files 2012-11-20 10:48:51,457-0800 INFO LateBindingScheduler JobQueue: 2 2012-11-20 10:48:51,458-0800 DEBUG vdl:dostagein CDM: file://localhost/in.rsf : DEFAULT 2012-11-20 10:48:51,460-0800 INFO vdl:dostagein END jobid=sfwindow_script-yrdq091l - Staging in finished 2012-11-20 10:48:51,460-0800 DEBUG vdl:execute2 JOB_START jobid=sfwindow_script-yrdq091l tr=sfwindow_script arguments=[in.rsf, _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0, 3, 1.0] tmpdir=simpleMapReduce-20121120-1048-lvoc0qx9/jobs/y/sfwindow_script-yrdq091l host=localhost 2012-11-20 10:48:51,464-0800 INFO GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-10-0-1-1-1353437329082) is /bin/bash shared/_swiftwrap sfwindow_script-yrdq091l -jobdir y -scratch -e ~/work/mapReduceScripts/bin/sfwindow_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ -if in.rsf -of _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 -k -cdmfile -status files -a in.rsf _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 3 1 2012-11-20 10:48:51,465-0800 INFO JobSubmissionTaskHandler Submit: in: /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9 command: /bin/bash /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9/shared/_swiftwrap sfwindow_script-yrdq091l -jobdir y -scratch -e ~/work/mapReduceScripts/bin/sfwindow_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ -if in.rsf -of _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 -k -cdmfile -status files -a in.rsf _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 3 1 2012-11-20 10:48:51,743-0800 INFO LateBindingScheduler JobQueue: 2 2012-11-20 10:48:51,745-0800 DEBUG vdl:checkjobstatus START jobid=sfwindow_script-yrdq091l 2012-11-20 10:48:51,747-0800 INFO LateBindingScheduler JobQueue: 2 2012-11-20 10:48:51,747-0800 INFO vdl:checkjobstatus SUCCESS jobid=sfwindow_script-yrdq091l - Success file found 2012-11-20 10:48:51,748-0800 DEBUG vdl:execute2 STAGING_OUT jobid=sfwindow_script-yrdq091l 2012-11-20 10:48:51,748-0800 INFO vdl:dostageout START jobid=sfwindow_script-yrdq091l - Staging out files 2012-11-20 10:48:51,748-0800 DEBUG vdl:dostageout stageouts: [[$, input_chunks[0]:RSFile - Open]] 2012-11-20 10:48:51,751-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_START srcname=elt-0 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ srchost=localhost destdir=_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ desthost=localhost provider=file 2012-11-20 10:48:51,759-0800 INFO LateBindingScheduler JobQueue: 2 2012-11-20 10:48:51,762-0800 INFO LateBindingScheduler JobQueue: 2 2012-11-20 10:48:51,762-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_END srcname=elt-0 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ srchost=localhost destdir=_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ desthost=localhost provider=file 2012-11-20 10:48:51,763-0800 INFO LateBindingScheduler JobQueue: 2 2012-11-20 10:48:51,764-0800 INFO vdl:dostageout END jobid=sfwindow_script-yrdq091l - Staging out finished 2012-11-20 10:48:51,765-0800 DEBUG vdl:execute2 JOB_END jobid=sfwindow_script-yrdq091l 2012-11-20 10:48:51,765-0800 INFO vdl:execute END_SUCCESS thread=0-10-0-1 tr=sfwindow_script 2012-11-20 10:48:51,766-0800 DEBUG appsplitfile PROCEDURE_END line=27 2012-11-20 10:48:51,767-0800 INFO SetFieldValue Set: processed_chunks[0]=null 2012-11-20 10:48:51,767-0800 DEBUG vdl:mains FOREACH_IT_END line=83 thread=0-10-0 2012-11-20 10:48:51,767-0800 INFO SetFieldValue Set: output_chunks[0]=null 2012-11-20 10:48:51,770-0800 DEBUG vdl:mains SCOPE thread=0-11-1-1 2012-11-20 10:48:51,770-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-11-1-1-0 name=trace 2012-11-20 10:48:51,774-0800 WARN trace SwiftScript trace: Adding , 1.0 2012-11-20 10:48:51,774-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-11-1-1-0 2012-11-20 10:48:51,776-0800 DEBUG appaddfiles PROCEDURE line=32 thread=0-11-1-1-1 name=appAddFiles 2012-11-20 10:48:52,266-0800 INFO WeightedHostScoreScheduler CONTACT_SELECTED host=localhost, score=3.211 2012-11-20 10:48:52,267-0800 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=sfwindow_script-0sdq091l thread=0-10-1-1-1 host=localhost replicationGroup=zrdq091l 2012-11-20 10:48:52,270-0800 INFO vdl:createdirset START jobid=sfwindow_script-0sdq091l host=localhost - Initializing directory structure 2012-11-20 10:48:52,270-0800 INFO vdl:createdirset END jobid=sfwindow_script-0sdq091l - Done initializing directory structure 2012-11-20 10:48:52,271-0800 INFO vdl:dostagein START jobid=sfwindow_script-0sdq091l - Staging in files 2012-11-20 10:48:52,273-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,273-0800 DEBUG vdl:dostagein CDM: file://localhost/in.rsf : DEFAULT 2012-11-20 10:48:52,274-0800 INFO vdl:dostagein END jobid=sfwindow_script-0sdq091l - Staging in finished 2012-11-20 10:48:52,274-0800 DEBUG vdl:execute2 JOB_START jobid=sfwindow_script-0sdq091l tr=sfwindow_script arguments=[in.rsf, _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1, 3, 2.0] tmpdir=simpleMapReduce-20121120-1048-lvoc0qx9/jobs/0/sfwindow_script-0sdq091l host=localhost 2012-11-20 10:48:52,277-0800 INFO GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-10-1-1-1-1353437329095) is /bin/bash shared/_swiftwrap sfwindow_script-0sdq091l -jobdir 0 -scratch -e ~/work/mapReduceScripts/bin/sfwindow_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ -if in.rsf -of _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1 -k -cdmfile -status files -a in.rsf _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1 3 2 2012-11-20 10:48:52,277-0800 INFO JobSubmissionTaskHandler Submit: in: /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9 command: /bin/bash /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9/shared/_swiftwrap sfwindow_script-0sdq091l -jobdir 0 -scratch -e ~/work/mapReduceScripts/bin/sfwindow_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ -if in.rsf -of _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1 -k -cdmfile -status files -a in.rsf _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1 3 2 2012-11-20 10:48:52,555-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,557-0800 DEBUG vdl:checkjobstatus START jobid=sfwindow_script-0sdq091l 2012-11-20 10:48:52,559-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,559-0800 INFO vdl:checkjobstatus SUCCESS jobid=sfwindow_script-0sdq091l - Success file found 2012-11-20 10:48:52,560-0800 DEBUG vdl:execute2 STAGING_OUT jobid=sfwindow_script-0sdq091l 2012-11-20 10:48:52,560-0800 INFO vdl:dostageout START jobid=sfwindow_script-0sdq091l - Staging out files 2012-11-20 10:48:52,560-0800 DEBUG vdl:dostageout stageouts: [[$, input_chunks[1]:RSFile - Open]] 2012-11-20 10:48:52,562-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_START srcname=elt-1 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ srchost=localhost destdir=_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ desthost=localhost provider=file 2012-11-20 10:48:52,563-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,566-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,567-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_END srcname=elt-1 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ srchost=localhost destdir=_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ desthost=localhost provider=file 2012-11-20 10:48:52,568-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,569-0800 INFO vdl:dostageout END jobid=sfwindow_script-0sdq091l - Staging out finished 2012-11-20 10:48:52,570-0800 DEBUG vdl:execute2 JOB_END jobid=sfwindow_script-0sdq091l 2012-11-20 10:48:52,571-0800 INFO vdl:execute END_SUCCESS thread=0-10-1-1 tr=sfwindow_script 2012-11-20 10:48:52,572-0800 INFO SetFieldValue Set: processed_chunks[1]=null 2012-11-20 10:48:52,575-0800 INFO vdl:execute START thread=0-11-1-1-1 tr=sfadd_script 2012-11-20 10:48:52,577-0800 DEBUG appsplitfile PROCEDURE_END line=27 2012-11-20 10:48:52,578-0800 INFO WeightedHostScoreScheduler CONTACT_SELECTED host=localhost, score=3.897 2012-11-20 10:48:52,578-0800 DEBUG vdl:mains FOREACH_IT_END line=83 thread=0-10-1 2012-11-20 10:48:52,580-0800 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=sfwindow_script-2sdq091l thread=0-10-2-1-1 host=localhost replicationGroup=xrdq091l 2012-11-20 10:48:52,582-0800 INFO vdl:createdirset START jobid=sfwindow_script-2sdq091l host=localhost - Initializing directory structure 2012-11-20 10:48:52,583-0800 INFO vdl:createdirset END jobid=sfwindow_script-2sdq091l - Done initializing directory structure 2012-11-20 10:48:52,583-0800 INFO vdl:dostagein START jobid=sfwindow_script-2sdq091l - Staging in files 2012-11-20 10:48:52,589-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,589-0800 DEBUG vdl:dostagein CDM: file://localhost/in.rsf : DEFAULT 2012-11-20 10:48:52,590-0800 INFO vdl:dostagein END jobid=sfwindow_script-2sdq091l - Staging in finished 2012-11-20 10:48:52,591-0800 DEBUG vdl:execute2 JOB_START jobid=sfwindow_script-2sdq091l tr=sfwindow_script arguments=[in.rsf, _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2, 3, 3.0] tmpdir=simpleMapReduce-20121120-1048-lvoc0qx9/jobs/2/sfwindow_script-2sdq091l host=localhost 2012-11-20 10:48:52,594-0800 INFO GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-10-2-1-1-1353437329109) is /bin/bash shared/_swiftwrap sfwindow_script-2sdq091l -jobdir 2 -scratch -e ~/work/mapReduceScripts/bin/sfwindow_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ -if in.rsf -of _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2 -k -cdmfile -status files -a in.rsf _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2 3 3 2012-11-20 10:48:52,595-0800 INFO JobSubmissionTaskHandler Submit: in: /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9 command: /bin/bash /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9/shared/_swiftwrap sfwindow_script-2sdq091l -jobdir 2 -scratch -e ~/work/mapReduceScripts/bin/sfwindow_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ -if in.rsf -of _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2 -k -cdmfile -status files -a in.rsf _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2 3 3 2012-11-20 10:48:52,831-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,833-0800 DEBUG vdl:checkjobstatus START jobid=sfwindow_script-2sdq091l 2012-11-20 10:48:52,835-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,835-0800 INFO vdl:checkjobstatus SUCCESS jobid=sfwindow_script-2sdq091l - Success file found 2012-11-20 10:48:52,835-0800 DEBUG vdl:execute2 STAGING_OUT jobid=sfwindow_script-2sdq091l 2012-11-20 10:48:52,836-0800 INFO vdl:dostageout START jobid=sfwindow_script-2sdq091l - Staging out files 2012-11-20 10:48:52,836-0800 DEBUG vdl:dostageout stageouts: [[$, input_chunks[2]:RSFile - Open]] 2012-11-20 10:48:52,837-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_START srcname=elt-2 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ srchost=localhost destdir=_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ desthost=localhost provider=file 2012-11-20 10:48:52,838-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,841-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,842-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_END srcname=elt-2 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ srchost=localhost destdir=_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/ desthost=localhost provider=file 2012-11-20 10:48:52,844-0800 INFO LateBindingScheduler JobQueue: 1 2012-11-20 10:48:52,845-0800 INFO vdl:dostageout END jobid=sfwindow_script-2sdq091l - Staging out finished 2012-11-20 10:48:52,846-0800 DEBUG vdl:execute2 JOB_END jobid=sfwindow_script-2sdq091l 2012-11-20 10:48:52,846-0800 INFO vdl:execute END_SUCCESS thread=0-10-2-1 tr=sfwindow_script 2012-11-20 10:48:52,847-0800 DEBUG appsplitfile PROCEDURE_END line=27 2012-11-20 10:48:52,847-0800 INFO SetFieldValue Set: processed_chunks[2]=null 2012-11-20 10:48:52,847-0800 DEBUG vdl:mains FOREACH_IT_END line=83 thread=0-10-2 2012-11-20 10:48:53,346-0800 INFO WeightedHostScoreScheduler CONTACT_SELECTED host=localhost, score=4.674 2012-11-20 10:48:53,348-0800 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=sfadd_script-3sdq091l thread=0-11-1-1-1-1 host=localhost replicationGroup=1sdq091l 2012-11-20 10:48:53,350-0800 INFO vdl:createdirset START jobid=sfadd_script-3sdq091l host=localhost - Initializing directory structure 2012-11-20 10:48:53,351-0800 INFO vdl:createdirs START path=_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ dir=simpleMapReduce-20121120-1048-lvoc0qx9/shared - Creating directory structure 2012-11-20 10:48:53,352-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,353-0800 INFO vdl:createdirset END jobid=sfadd_script-3sdq091l - Done initializing directory structure 2012-11-20 10:48:53,353-0800 INFO vdl:dostagein START jobid=sfadd_script-3sdq091l - Staging in files 2012-11-20 10:48:53,355-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,356-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,356-0800 DEBUG vdl:dostagein CDM: file://localhost/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1 : DEFAULT 2012-11-20 10:48:53,356-0800 DEBUG vdl:dostagein CDM: file://localhost/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 : DEFAULT 2012-11-20 10:48:53,357-0800 INFO vdl:dostagein END jobid=sfadd_script-3sdq091l - Staging in finished 2012-11-20 10:48:53,357-0800 DEBUG vdl:execute2 JOB_START jobid=sfadd_script-3sdq091l tr=sfadd_script arguments=[_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1, _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1, _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0] tmpdir=simpleMapReduce-20121120-1048-lvoc0qx9/jobs/3/sfadd_script-3sdq091l host=localhost 2012-11-20 10:48:53,359-0800 INFO GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-11-1-1-1-1-1353437329126) is /bin/bash shared/_swiftwrap sfadd_script-3sdq091l -jobdir 3 -scratch -e ~/work/mapReduceScripts/bin/sfadd_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/|_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ -if _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1|_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 -of _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 -k -cdmfile -status files -a _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1 _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 2012-11-20 10:48:53,360-0800 INFO JobSubmissionTaskHandler Submit: in: /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9 command: /bin/bash /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9/shared/_swiftwrap sfadd_script-3sdq091l -jobdir 3 -scratch -e ~/work/mapReduceScripts/bin/sfadd_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/|_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ -if _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1|_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 -of _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 -k -cdmfile -status files -a _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-1 _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-0 2012-11-20 10:48:53,640-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,642-0800 DEBUG vdl:checkjobstatus START jobid=sfadd_script-3sdq091l 2012-11-20 10:48:53,644-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,644-0800 INFO vdl:checkjobstatus SUCCESS jobid=sfadd_script-3sdq091l - Success file found 2012-11-20 10:48:53,644-0800 DEBUG vdl:execute2 STAGING_OUT jobid=sfadd_script-3sdq091l 2012-11-20 10:48:53,645-0800 INFO vdl:dostageout START jobid=sfadd_script-3sdq091l - Staging out files 2012-11-20 10:48:53,645-0800 DEBUG vdl:dostageout stageouts: [[$, output_chunks[1]:RSFile - Open]] 2012-11-20 10:48:53,646-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_START srcname=elt-1 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ srchost=localhost destdir=_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ desthost=localhost provider=file 2012-11-20 10:48:53,648-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,651-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,652-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_END srcname=elt-1 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ srchost=localhost destdir=_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ desthost=localhost provider=file 2012-11-20 10:48:53,653-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,654-0800 INFO vdl:dostageout END jobid=sfadd_script-3sdq091l - Staging out finished 2012-11-20 10:48:53,655-0800 DEBUG vdl:execute2 JOB_END jobid=sfadd_script-3sdq091l 2012-11-20 10:48:53,656-0800 INFO vdl:execute END_SUCCESS thread=0-11-1-1-1 tr=sfadd_script 2012-11-20 10:48:53,657-0800 DEBUG appaddfiles PROCEDURE_END line=32 2012-11-20 10:48:53,658-0800 DEBUG vdl:mains SCOPE thread=0-11-2-1 2012-11-20 10:48:53,659-0800 DEBUG vdl:mains INTERNALPROC_START thread=0-11-2-1-0 name=trace 2012-11-20 10:48:53,663-0800 WARN trace SwiftScript trace: Adding , 2.0 2012-11-20 10:48:53,663-0800 DEBUG vdl:mains INTERNALPROC_END thread=0-11-2-1-0 2012-11-20 10:48:53,664-0800 DEBUG appaddfiles PROCEDURE line=32 thread=0-11-2-1-1 name=appAddFiles 2012-11-20 10:48:53,666-0800 INFO vdl:execute START thread=0-11-2-1-1 tr=sfadd_script 2012-11-20 10:48:53,668-0800 INFO WeightedHostScoreScheduler CONTACT_SELECTED host=localhost, score=5.766 2012-11-20 10:48:53,671-0800 DEBUG vdl:execute2 THREAD_ASSOCIATION jobid=sfadd_script-5sdq091l thread=0-11-2-1-1-1 host=localhost replicationGroup=4sdq091l 2012-11-20 10:48:53,672-0800 INFO vdl:createdirset START jobid=sfadd_script-5sdq091l host=localhost - Initializing directory structure 2012-11-20 10:48:53,673-0800 INFO vdl:createdirset END jobid=sfadd_script-5sdq091l - Done initializing directory structure 2012-11-20 10:48:53,673-0800 INFO vdl:dostagein START jobid=sfadd_script-5sdq091l - Staging in files 2012-11-20 10:48:53,675-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,675-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,676-0800 DEBUG vdl:dostagein CDM: file://localhost/_concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2 : DEFAULT 2012-11-20 10:48:53,676-0800 DEBUG vdl:dostagein CDM: file://localhost/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 : DEFAULT 2012-11-20 10:48:53,677-0800 INFO vdl:dostagein END jobid=sfadd_script-5sdq091l - Staging in finished 2012-11-20 10:48:53,677-0800 DEBUG vdl:execute2 JOB_START jobid=sfadd_script-5sdq091l tr=sfadd_script arguments=[_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-2, _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2, _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1] tmpdir=simpleMapReduce-20121120-1048-lvoc0qx9/jobs/5/sfadd_script-5sdq091l host=localhost 2012-11-20 10:48:53,679-0800 INFO GridExec TASK_DEFINITION: Task(type=JOB_SUBMISSION, identity=urn:0-11-2-1-1-1-1353437329142) is /bin/bash shared/_swiftwrap sfadd_script-5sdq091l -jobdir 5 -scratch -e ~/work/mapReduceScripts/bin/sfadd_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/|_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ -if _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2|_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 -of _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-2 -k -cdmfile -status files -a _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-2 _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2 _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 2012-11-20 10:48:53,679-0800 INFO JobSubmissionTaskHandler Submit: in: /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9 command: /bin/bash /var/tmp/simpleMapReduce-20121120-1048-lvoc0qx9/shared/_swiftwrap sfadd_script-5sdq091l -jobdir 5 -scratch -e ~/work/mapReduceScripts/bin/sfadd_script -out stdout.txt -err stderr.txt -i -d _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array/|_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ -if _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2|_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 -of _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-2 -k -cdmfile -status files -a _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-2 _concurrent/input_chunks-f502a959-d5a0-4a17-8141-8237de5afbc9--array//elt-2 _concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array//elt-1 2012-11-20 10:48:53,912-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,914-0800 DEBUG vdl:checkjobstatus START jobid=sfadd_script-5sdq091l 2012-11-20 10:48:53,915-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,916-0800 INFO vdl:checkjobstatus SUCCESS jobid=sfadd_script-5sdq091l - Success file found 2012-11-20 10:48:53,916-0800 DEBUG vdl:execute2 STAGING_OUT jobid=sfadd_script-5sdq091l 2012-11-20 10:48:53,917-0800 INFO vdl:dostageout START jobid=sfadd_script-5sdq091l - Staging out files 2012-11-20 10:48:53,917-0800 DEBUG vdl:dostageout stageouts: [[$, output_chunks[2]:RSFile - Open]] 2012-11-20 10:48:53,919-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_START srcname=elt-2 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ srchost=localhost destdir=_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ desthost=localhost provider=file 2012-11-20 10:48:53,920-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,923-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,924-0800 DEBUG vdl:dostageout FILE_STAGE_OUT_END srcname=elt-2 srcdir=simpleMapReduce-20121120-1048-lvoc0qx9/shared/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ srchost=localhost destdir=_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/ desthost=localhost provider=file 2012-11-20 10:48:53,925-0800 INFO LateBindingScheduler JobQueue: 0 2012-11-20 10:48:53,926-0800 INFO vdl:dostageout END jobid=sfadd_script-5sdq091l - Staging out finished 2012-11-20 10:48:53,927-0800 DEBUG vdl:execute2 JOB_END jobid=sfadd_script-5sdq091l 2012-11-20 10:48:53,927-0800 INFO vdl:execute END_SUCCESS thread=0-11-2-1-1 tr=sfadd_script 2012-11-20 10:48:53,928-0800 INFO SetFieldValue Set: output_data=null 2012-11-20 10:48:53,928-0800 DEBUG appaddfiles PROCEDURE_END line=32 2012-11-20 10:48:53,933-0800 INFO SetFieldValue Set: output_data=null 2012-11-20 10:48:53,935-0800 DEBUG VDL2ExecutionContext Failed to copy output_chunks[2]:RSFile - Closed to output_data:RSFile - Open Caused by: java.lang.Exception Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 Failed to copy output_chunks[2]:RSFile - Closed to output_data:RSFile - Open Caused by: java.lang.Exception Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 Caused by: Failed to copy output_chunks[2]:RSFile - Closed to output_data:RSFile - Open Caused by: java.lang.Exception Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 at org.griphyn.vdl.karajan.lib.SetFieldValue.function(SetFieldValue.java:56) at org.griphyn.vdl.karajan.lib.VDLFunction.post(VDLFunction.java:62) at org.globus.cog.karajan.workflow.nodes.AbstractSequentialWithArguments.futureModified(AbstractSequentialWithArguments.java:208) at org.griphyn.vdl.karajan.lib.FileCopier.actions(FileCopier.java:98) at org.griphyn.vdl.karajan.lib.FileCopier.close(FileCopier.java:125) at org.griphyn.vdl.karajan.lib.FileCopier.statusChanged(FileCopier.java:136) at org.globus.cog.abstraction.impl.common.task.TaskImpl.notifyListeners(TaskImpl.java:240) at org.globus.cog.abstraction.impl.common.task.TaskImpl.setStatus(TaskImpl.java:228) at org.globus.cog.abstraction.impl.common.AbstractDelegatedTaskHandler.failTask(AbstractDelegatedTaskHandler.java:54) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.transferFailed(DelegatedFileTransferHandler.java:553) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:499) at java.lang.Thread.run(Thread.java:636) Caused by: Failed to copy output_chunks[2]:RSFile - Closed to output_data:RSFile - Open Caused by: java.lang.Exception Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 at org.griphyn.vdl.karajan.lib.SetFieldValue.copyNonComposite(SetFieldValue.java:176) at org.griphyn.vdl.karajan.lib.SetFieldValue.deepCopy(SetFieldValue.java:116) at org.griphyn.vdl.karajan.lib.SetFieldValue.function(SetFieldValue.java:49) ... 11 more Caused by: java.lang.Exception at org.griphyn.vdl.karajan.lib.FileCopier.statusChanged(FileCopier.java:135) ... 6 more Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 at org.globus.cog.abstraction.impl.file.local.FileResourceImpl.getFile(FileResourceImpl.java:225) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.doSource(DelegatedFileTransferHandler.java:254) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:484) ... 1 more 2012-11-20 10:48:53,974-0800 INFO ExecutionContext Detailed exception: Failed to copy output_chunks[2]:RSFile - Closed to output_data:RSFile - Open Caused by: java.lang.Exception Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 Caused by: Failed to copy output_chunks[2]:RSFile - Closed to output_data:RSFile - Open Caused by: java.lang.Exception Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 at org.griphyn.vdl.karajan.lib.SetFieldValue.function(SetFieldValue.java:56) at org.griphyn.vdl.karajan.lib.VDLFunction.post(VDLFunction.java:62) at org.globus.cog.karajan.workflow.nodes.AbstractSequentialWithArguments.futureModified(AbstractSequentialWithArguments.java:208) at org.griphyn.vdl.karajan.lib.FileCopier.actions(FileCopier.java:98) at org.griphyn.vdl.karajan.lib.FileCopier.close(FileCopier.java:125) at org.griphyn.vdl.karajan.lib.FileCopier.statusChanged(FileCopier.java:136) at org.globus.cog.abstraction.impl.common.task.TaskImpl.notifyListeners(TaskImpl.java:240) at org.globus.cog.abstraction.impl.common.task.TaskImpl.setStatus(TaskImpl.java:228) at org.globus.cog.abstraction.impl.common.AbstractDelegatedTaskHandler.failTask(AbstractDelegatedTaskHandler.java:54) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.transferFailed(DelegatedFileTransferHandler.java:553) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:499) at java.lang.Thread.run(Thread.java:636) Caused by: Failed to copy output_chunks[2]:RSFile - Closed to output_data:RSFile - Open Caused by: java.lang.Exception Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 at org.griphyn.vdl.karajan.lib.SetFieldValue.copyNonComposite(SetFieldValue.java:176) at org.griphyn.vdl.karajan.lib.SetFieldValue.deepCopy(SetFieldValue.java:116) at org.griphyn.vdl.karajan.lib.SetFieldValue.function(SetFieldValue.java:49) ... 11 more Caused by: java.lang.Exception at org.griphyn.vdl.karajan.lib.FileCopier.statusChanged(FileCopier.java:135) ... 6 more Caused by: org.globus.cog.abstraction.impl.file.FileNotFoundException: File not found: /users/slic/tlai/work/mapReduceScripts/./_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/_concurrent/output_chunks-49bb43aa-7ccf-4d81-9189-ba8a20c8627c--array/elt-2 at org.globus.cog.abstraction.impl.file.local.FileResourceImpl.getFile(FileResourceImpl.java:225) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.doSource(DelegatedFileTransferHandler.java:254) at org.globus.cog.abstraction.impl.fileTransfer.DelegatedFileTransferHandler.run(DelegatedFileTransferHandler.java:484) ... 1 more 2012-11-20 10:48:53,975-0800 INFO Loader Swift finished with errors