[Swift-devel] Formatting kickstart records

Michael Wilde wilde at mcs.anl.gov
Tue Sep 11 12:49:56 CDT 2007 

Hi Brian,

The cheat-sheet page at 
http://www.cedps.net/wiki/index.php/LoggingBestPracticesCheatSheet
was very helpful.

We'll need to get a place in the eventname hierarchy - like 
org.globus.swift.* - I assume that's what we should use.

Our timestamps are close in format but use local time with a TZ suffix. 
We could change to GMT (I assume thats what Z means)

What's the standard and use for GUIDs? I assume that can be used to tie 
together events across components, but I'm not sure how to make the 
correlation. Swift generates its own GUIDs internally for various 
objects in the lifetime of a workflow (eg jobs).

- Mike

 From http://www.cedps.net/wiki/index.php/LoggingBestPracticesCheatSheet:

     *  Use name=value pairs only
     * Required fields:
           o ts=ISO8601 timestamp {ts=2007-06-12T14:32:15.145455Z}
           o event=hierarchical event name {event=org.foo.component.start}
           o guid=global identifier or id=local identifier. 
{guid=8AE1154D-B79E-49B6-AB77-575D956FCE4D} or {id=1143}
     * Other standard fields:
           o level=Logging level {level=INFO}
                 + Levels: FATAL, ALERT, CRITICAL, ERROR, WARNING, 
NOTICE, INFO, DEBUG, TRACE
           o prog=Program name {prog=GridFTP-v4.0.2}
           o status=Status of .end event status=-1
                 + integer: < 0 is an error, >= 0 is success
     * Wrap actions with two events: one .start and one .end:
           o (start) event=org.foo.component.loop.start
           o (end) event=org.foo.component.loop.end status=0

examples:

  Globus Gatekeeper

     * ts=2006-12-08T18:39:23.114369Z event=org.globus.gatekeeper.start 
guid=55A0DF43-D7AB-40BF-A023-04444B93F76E 
remoteHost=gridhost.yoursite.gov:NNNN localHost=myhost.foo.gov:NNNN 
requestType=jobSubmit
     * ts=2006-12-08T18:39:23.114369Z 
event=org.globus.gatekeeper.authn.x509.start 
guid=55A0DF43-D7AB-40BF-A023-04444B93F76E DN=”/O=CEDS/CN=Some User”
     * ts=2006-12-08T18:39:23.114369Z 
event=org.globus.gatekeeper.authn.x509.end 
guid=55A0DF43-D7AB-40BF-A023-04444B93F76E DN=”/O=CEDS/CN=Some User” status=0
     * ts=2006-12-08T18:39:23.114369Z 
event=org.globus.gatekeeper.authz.GUMS.start 
guid=55A0DF43-D7AB-40BF-A023-04444B93F76E DN=”/O=CEDS/CN=Some User” 
mappingService="https://cmssrv08.fnal.gov:8443/gums/services/ 
GUMSAuthorizationServicePort”
     * ts=2006-12-08T18:39:23.114369Z 
event=org.globus.gatekeeper.authz.GUMS.end 
guid=55A0DF43-D7AB-40BF-A023-04444B93F76E DN=”/O=CEDS/CN=Some User” 
localUser=gridex localUID=10657 localGID=10657 gridSecurityHTTPBodyFD=8 
status=0
     * ts=2006-12-08T18:39:23.114369Z 
event=org.globus.gatekeeper.jobManager.start 
guid=55A0DF43-D7AB-40BF-A023-04444B93F76E 
path="/opt/globus/libexec/globus-job-manager" 
gatekeeperJmId="2006-11-09.00:06:28.0000006577.0000000000" 
executionHost=128.105.121.51 securityContextFD=11 childID=6639
     * ts=2006-12-08T18:39:23.114369Z 
event=org.globus.gatekeeper.jobManager.end 
guid=55A0DF43-D7AB-40BF-A023-04444B93F76E status=0
     * ts=2006-12-08T18:39:23.114369Z event=org.globus.gatekeeper.end 
guid=55A0DF43-D7AB-40BF-A023-04444B93F76E status=0

[edit]
Globus GridFTP Server

     * ts=2006-12-08T18:39:23.114369Z event=org.globus.gridFTP.start 
prog=GridFTP-4.0.3 localHost=myhost remoteHost=somehost.gov:56010 
serverMode=inetd guid=D4E922E1-6F7D-4752-B126-013BFE71C80B
     * ts=2006-12-08T18:39:23.114567Z 
event=org.globus.gridFTP.authn.x509.start 
DN=“/DC=org/DC=doegrids/OU=People/CN=Somebody” 
guid=D4E922E1-6F7D-4752-B126-013BFE71C80B
     * ts=2006-12-08T18:39:23.114567Z 
event=org.globus.gridFTP.authn.x509.end 
DN=“/DC=org/DC=doegrids/OU=People/CN=Somebody” 
guid=D4E922E1-6F7D-4752-B126-013BFE71C80B status=0
     * ts=2006-12-08T18:39:23.114567Z 
event=org.globus.gridFTP.authz.gridmap.start 
DN=“/DC=org/DC=doegrids/OU=People/CN=Somebody” 
guid=D4E922E1-6F7D-4752-B126-013BFE71C80B
     * ts=2006-12-08T18:39:25.514369Z 
event=org.globus.gridFTP.authz.gridmap.end 
DN=“/DC=org/DC=doegrids/OU=People/CN=Somebody” localUser=uscmspool381 
guid=D4E922E1-6F7D-4752-B126-013BFE71C80B status=0
     * ts=2006-12-08T18:39:25.864369Z 
event=org.globus.gridFTP.transfer.start infile=/tmp/myfile 
tcpBufferSize=128KB dataBlockSize=262144 numStreams=1 numStripes=1 
destHost=129.79.4.64 guid=D4E922E1-6F7D-4752-B126-013BFE71C80B
     * ts=2006-12-08T18:45:02.214369Z 
event=org.globus.gridFTP.transfer.end infile=/tmp/myfile 
bytesTransferred=678433 guid=D4E922E1-6F7D-4752-B126-013BFE71C80B status=0
     * ts=2006-12-08T18:45:02.214386Z event=org.globus.gridFTP.end 
guid=D4E922E1-6F7D-4752-B126-013BFE71C80B status=226







Brian Tierney wrote:
> 
> Hi Mike:
> 
> The logging document is here:
> 
> http://www.cedps.net/wiki/index.php/LoggingBestPractices
> 
> and a paper describing the higher-level vision is here:
> 
> http://www.cedps.net/wiki/images/e/ec/Grid2007.pdf
> 
> It should be quite easy to convert your logs to the CEDPS format.
> 
> Let's read each others papers and then talk more.
> 
> 
> 
> 
> Michael Wilde wrote:
>> Brian, Suchandra,
>>
>> In the Swift workflow system we use a tool (developed as part of the 
>> GriPhyN Virtual Data System VDS) called "kickstart" to launch programs 
>> on Grid sites and record their execution environment, exit status and 
>> resource consumption as an XML document. Kickstart is a simple utility 
>> runs the real app as a child process and records its info; it usually 
>> run under GRAM.
>>
>> We're now developing some tools to flexibly format and and query this 
>> info, as its very useful in troubleshooting.
>>
>> Ian suggests below that we should integrate this mechanism with a 
>> CEDPS-defined log format. Ive looked at the CEDPS wiki, but have not 
>> yet found where this format is defined and how it relates to the 
>> myriad sources of gird log info.
>>
>> Could you point us to some information on this format and how you 
>> envision that tools like kickstart would integrate with it?
>>
>> Any thoughts you have on how we should approach logging in Swift would 
>> be welcome as well.
>>
>> For reference: Swift is described at www.ci.uchicago.edu/swift;
>> A sample kickstart record is at:
>> http://www.ci.uchicago.edu/~wilde/runs/uc.teragrid/runs/run23/kickstart/angle4-0aac5zgi-kickstart.xml 
>>
>> A paper on kickstart is at:
>> http://www.ci.uchicago.edu/swift/papers/Kickstarting2006.pdf
>>
>> Thanks,
>>
>> Mike
>>
>>
>> Ian Foster wrote:
>>> is this format in the "standard log format" that CEDPS defined? I 
>>> would think it should be.
>>>
>>> Michael Wilde wrote:
>>>> I started a small perl script to format kickstart records.
>>>>
>>>> For now, for each kickstart output file on the cmd line it prints 
>>>> one-liners of the form:
>>>>
>>>> Start=2007-09-09T00:24:43.161-05:00 duration=83.993 user=82.470 
>>>> sys=1.360 machine=i686 host=tg-v050.uc.teragrid.org
>>>>
>>>> but its pretty generalizable.
>>>>
>>>> I did this to find the min, max and stats on run times, looking for 
>>>> outliers that are holding up the workflow.
>>>>
>>>> If anyone has a similar/better tool please point it out, otherwise 
>>>> I'll continue to enhance this. Suggestions for a better approach are 
>>>> welcome.
>>>>
>>>> Pavel (summer student) did something like this in C a while back; I 
>>>> thought that was added to vds/contrib at that time but I dont see it 
>>>> in the latest VDS release.  Need to hunt it down.
>>>>
>>>> This perl script is very simple and easy, but rather slow on 1000 
>>>> kickstart records (need to get timings; Im sure it can be improved, 
>>>> possibly by grabbing multiple fields on each XPath call.
>>>>
>>>> - Mike
>>>>
>>>> $ cat ~/vds/kix
>>>> #!/usr/bin/perl -w -I/home/wilde/vds
>>>> #                  ^^^ How to best set the module path?
>>>>
>>>> # Print fields from a list of invocation record xml files
>>>>
>>>> use strict;
>>>> use XML::XPath;
>>>> use XML::XPath::XMLParser;
>>>>
>>>> while(@ARGV) {
>>>>   print_irec(shift @ARGV);
>>>> }
>>>>
>>>> sub print_irec
>>>> {
>>>>   my $irec = shift;
>>>>   my $xp = XML::XPath->new(filename => $irec);
>>>>
>>>>   my $start = $xp->findvalue('/invocation/mainjob/@start');
>>>>   my $utime = $xp->findvalue('/invocation/mainjob/usage/@utime');
>>>>   my $stime = $xp->findvalue('/invocation/mainjob/usage/@stime');
>>>>   my $duration = $xp->findvalue('/invocation/mainjob/@duration');
>>>>   my $machine = $xp->findvalue('/invocation/uname/@machine');
>>>>   my $host = $xp->findvalue('/invocation/@hostname');
>>>>
>>>>   print "Start=$start duration=$duration user=$utime sys=$stime 
>>>> machine=$machine host=$host\n";
>>>> }
>>>>
>>>> _______________________________________________
>>>> Swift-devel mailing list
>>>> Swift-devel at ci.uchicago.edu
>>>> http://mail.ci.uchicago.edu/mailman/listinfo/swift-devel
>>>>
>>>
>

More information about the Swift-devel mailing list