[Swift-devel] [Bug 186] New: File-not-found errors in swift log should be sent to stdout/err

bugzilla-daemon at mcs.anl.gov bugzilla-daemon at mcs.anl.gov
Sun Mar 22 11:34:10 CDT 2009 

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=186

           Summary: File-not-found errors in swift log should be sent to
                    stdout/err
           Product: Swift
           Version: unspecified
          Platform: All
        OS/Version: All
            Status: NEW
          Keywords: error-handling
          Severity: normal
          Priority: P2
         Component: SwiftScript language
        AssignedTo: benc at hawaga.org.uk
        ReportedBy: wilde at mcs.anl.gov


In a case when the files that a dataset is mapped to are not found, the details
of this error seem to be left buried in the .log file, and what shows up on
stdout/err is the much more cryptic error that the app did not produce the an
expected output file.  Its not yet clear to me if swift even got to the point
of executing the app, though.

I get this on stdout/err:
--
Swift svn swift-r2724 (swift modified locally) cog-r2333

RunID: 20090322-1102-rveraq3f
Progress: 
Failed to transfer wrapper log from t1-20090322-1102-rveraq3f/info/m on
localhost
Execution failed:
        java.io.FileNotFoundException:
_concurrent/results-c6c862ba-4992-4726-b193-c92753858e0e-7 (No such file or
directory)
sur$ 
--

Yet the log is filled with errors, like these, which would have more
immediately told me what was wrong:

--

sur$ ./checklog       
Errors found in swift log t1-20090322-1102-rveraq3f.log: ( -rw-rw-r-- 1 wilde
users 168177 Mar 22 11:02 t1-20090322-1102-rveraq3f.log ):

2009-03-22 11:02:29,988-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-15-1237737749283) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.rmsd
2009-03-22 11:02:29,997-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-6-1237737749285) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.rmsd
2009-03-22 11:02:30,000-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-7-1237737749288) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.log
2009-03-22 11:02:30,009-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-8-1237737749292) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.pdt
2009-03-22 11:02:30,012-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-15-1237737749297) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.rmsd
2009-03-22 11:02:30,015-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-9-1237737749303) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.rmsd
2009-03-22 11:02:30,018-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-5-1237737749300) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.pdt
2009-03-22 11:02:30,026-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-1-1237737749305) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.log
2009-03-22 11:02:30,027-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-4-1237737749307) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.log
2009-03-22 11:02:30,030-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-6-1237737749309) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.rmsd
2009-03-22 11:02:30,031-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-12-1237737749290) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.rmsd
2009-03-22 11:02:30,041-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-14-1237737749315) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.pdt
2009-03-22 11:02:30,039-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-13-1237737749312) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.log
2009-03-22 11:02:30,041-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-10-1237737749321) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.log
2009-03-22 11:02:30,044-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-2-1237737749319) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.pdt
2009-03-22 11:02:30,047-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-15-1237737749326) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.rmsd
2009-03-22 11:02:30,049-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-3-1237737749323) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.rmsd
2009-03-22 11:02:30,053-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-1-1237737749335) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.log
2009-03-22 11:02:30,053-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-5-1237737749333) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.pdt
2009-03-22 11:02:30,056-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-6-1237737749337) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.rmsd
2009-03-22 11:02:30,056-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-12-1237737749341) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.rmsd
2009-03-22 11:02:30,057-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-4-1237737749339) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.log
2009-03-22 11:02:30,060-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-8-1237737749350) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.pdt
2009-03-22 11:02:30,060-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-10-1237737749353) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.log
2009-03-22 11:02:30,060-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-7-1237737749330) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.log
2009-03-22 11:02:30,063-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-11-1237737749344) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.pdt
2009-03-22 11:02:30,064-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-2-1237737749355) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.pdt
2009-03-22 11:02:30,067-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-3-1237737749357) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.rmsd
2009-03-22 11:02:30,072-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-5-1237737749370) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.pdt
2009-03-22 11:02:30,073-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-1-1237737749364) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.log
2009-03-22 11:02:30,073-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-12-1237737749368) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.rmsd
2009-03-22 11:02:30,076-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-9-1237737749379) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.rmsd
2009-03-22 11:02:30,076-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-13-1237737749366) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.log
2009-03-22 11:02:30,077-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-4-1237737749372) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/00/T1af7.0000.0000.log
2009-03-22 11:02:30,082-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-3-1237737749386) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.rmsd
2009-03-22 11:02:30,083-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-8-1237737749381) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.pdt
2009-03-22 11:02:30,084-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-7-1237737749391) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.log
2009-03-22 11:02:30,083-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-1237737749398) setting status to Failed File not found:
/home/wilde/oops/swift/work/t1-20090322-1102-rveraq3f/jobs/m/analyze_round-m9us4b8j/stderr.txt
2009-03-22 11:02:30,085-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-9-1237737749400) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/01/T1af7.0000.0001.rmsd
2009-03-22 11:02:30,086-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-2-1237737749395) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/04/T1af7.0000.0004.pdt
2009-03-22 11:02:30,087-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-11-1237737749402) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.pdt
2009-03-22 11:02:30,090-0500 DEBUG TaskImpl Task(type=FILE_OPERATION,
identity=urn:0-7-0-1-1237737749414) setting status to Failed
org.globus.cog.abstraction.impl.file.FileNotFoundException:
analyze_round-m9us4b8j-stderr.txt not found.
2009-03-22 11:02:30,090-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-10-1237737749404) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.log
2009-03-22 11:02:30,091-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-13-1237737749406) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.log
2009-03-22 11:02:30,093-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-11-1237737749417) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/02/T1af7.0000.0002.pdt
2009-03-22 11:02:30,095-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-14-1237737749384) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.pdt
2009-03-22 11:02:30,095-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-1237737749421) setting status to Failed File not found:
/home/wilde/oops/swift/work/t1-20090322-1102-rveraq3f/jobs/m/analyze_round-m9us4b8j/_concurrent/results-c6c862ba-4992-4726-b193-c92753858e0e-7
2009-03-22 11:02:30,097-0500 DEBUG TaskImpl Task(type=FILE_OPERATION,
identity=urn:0-7-0-1-1237737749426) setting status to Failed
org.globus.cog.abstraction.impl.file.FileNotFoundException:
analyze_round-m9us4b8j-_concurrent/results-c6c862ba-4992-4726-b193-c92753858e0e-7
not found.
2009-03-22 11:02:30,099-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-14-1237737749428) setting status to Failed File not found:
/gpfs/home/wilde/oops/swift/./out.n7b/T1af7/0000/00/03/T1af7.0000.0003.pdt
2009-03-22 11:02:30,105-0500 DEBUG TaskImpl Task(type=FILE_TRANSFER,
identity=urn:0-7-0-1-1237737749435) setting status to Failed File not found:
/home/wilde/oops/swift/work/t1-20090322-1102-rveraq3f/info/m/analyze_round-m9us4b8j-info
2009-03-22 11:02:30,107-0500 DEBUG TaskImpl Task(type=FILE_OPERATION,
identity=urn:0-7-0-1-1237737749438) setting status to Failed
org.globus.cog.abstraction.impl.file.FileNotFoundException:
analyze_round-m9us4b8j-info not found.
2009-03-22 11:02:30,108-0500 WARN  vdl:transferwrapperlog Failed to transfer
wrapper log from t1-20090322-1102-rveraq3f/info/m on localhost
2009-03-22 11:02:30,108-0500 DEBUG vdl:transferwrapperlog Exception for wrapper
log failure from t1-20090322-1102-rveraq3f/info/m on localhost: File not found:
/home/wilde/oops/swift/work/t1-20090322-1102-rveraq3f/info/m/analyze_round-m9us4b8j-info
2009-03-22 11:02:30,113-0500 INFO  vdl:execute END_FAILURE thread=0-7-0
tr=analyze_round
2009-03-22 11:02:30,117-0500 INFO  SetFutureFault Failing
org.griphyn.vdl.mapping.RootDataNode identifier
tag:benc at ci.uchicago.edu,2008:swift:dataset:20090322-1102-3yoo96q3:720000000020
type file with no value at dataset=results (not closed) (mapping=false)
2009-03-22 11:02:30,121-0500 INFO  SetFutureFault Failing
org.griphyn.vdl.mapping.RootDataNode identifier
tag:benc at ci.uchicago.edu,2008:swift:dataset:20090322-1102-3yoo96q3:720000000018
type SecSeq with no value at dataset=nsecseq (not closed) (mapping=false)
2009-03-22 11:02:30,140-0500 DEBUG Loader Swift finished with errors
sur$ 
--

Possibly relevant, my properties were:

lazy.errors=true
wrapperlog.always.transfer=true

# remove all limits on job submit rates

throttle.submit=off
throttle.host.submit=off
throttle.score.job.factor=off

# set data transfer and data management rate limits very high

throttle.transfers=1000
throttle.file.operations=1000

# Keep the workflow work directories intact on the execution sites

sitedir.keep=true

# Dont retry any job failues (while we are debugging. for production =2 is
better)

execution.retries=0

sur$

-- 
Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching the reporter.

More information about the Swift-devel mailing list