Tracing Jobs

This page helps you find out, given some "ID" for a job, how to find out other information.

Tracing a job given the PBS ID

Situation : you have identified the job via qstat, so you have an identifier like

7416345

or

7416345.stro.nikhef.nl

You report the misbehaving job to the VO in question, and they ask you for the grid job ID. First, log into stro and look for the job in the PBS server logs:

stro:~> grep 7416345 /var/spool/pbs/server_logs/2010083*
/var/spool/pbs/server_logs/20100830:08/30/2010 13:25:19;0008;PBS_Server;Job;7416345.stro.nikhef.nl;Job Queued at request of lhcbpi01@gazon.nikhef.nl, owner = lhcbpi01@gazon.nikhef.nl, job name = STDIN, queue = lhcb
[ ... ]
/var/spool/pbs/server_logs/20100830:08/30/2010 13:25:24;0002;PBS_Server;Job;7416345.stro.nikhef.nl;child reported success for job after 0 seconds (dest=wn-lui2-008.farm.nikhef.nl), rc=0
[ ... ]
/var/spool/pbs/server_logs/20100831:08/31/2010 10:26:46;0010;PBS_Server;Job;7416345.stro.nikhef.nl;Exit_status=0 resources_used.cput=00:00:00 resources_used.mem=0kb resources_used.vmem=0kb resources_used.walltime=21:01:22

Given these lines you already have lots of information: you know which CE the job entered the system from, this is given by the "owner", lhcbpi01@gazon.nikhef.nl, hence the CE in this case was "gazon". You also know which worker node the job ran on (dest=wn-lui2-008.farm.nikhef.nl) and the last line tells you what time the job ended, how much cpu and memory it used, and wall time. The record for the memory is wrong in this case (0 kb memory used, not very likely!), most likely because there was a power glitch on this day, causing the WN to go down during the job execution ... the end record came when the WN came back up and the job was already gone.

What to do next, depends on whether the CE in question is an LCG-CE or a CREAM CE.

LCG CE tracing

For an lcg-CE, log into the CE. Remember the jobid was 7416345 ... first find this jobID in the gatekeeper log file:

gazon:~> grep 7416345 /var/log/globus-gatekeeper.log
JMA 2010/08/30 13:25:20 GATEKEEPER_JM_ID 2010-08-30.13:25:15.0000011355.0000000000 has GRAM_SCRIPT_JOB_ID 7416345.stro.nikhef.nl manager type pbs

The gatekeeper's ID for the job is the long string after the tag GATEKEEPER_JM_ID, so now grep the gatekeeper log file on that string:

gazon:~> grep 2010-08-30.13:25:15.0000011355 /var/log/globus-gatekeeper.log
LCMAPS 0: 2010-08-30.13:25:15.0000011355.0000000000 : 
LCMAPS 7: 2010-08-30.13:25:15.0000011355.0000000000 : Initialization LCMAPS version 1.4.7
[ ... lots of LCMAPS messages skipped ] 
PID: 11355 -- Notice: 0: GATEKEEPER_JM_ID 2010-08-30.13:25:15.0000011355.0000000000 for /DC=es/DC=irisgrid/O=ecm-ub/CN=Ricardo-Graciani-Diaz on 128.142.167.136
JMA 2010/08/30 13:25:15 GATEKEEPER_JM_ID 2010-08-30.13:25:15.0000011355.0000000000 has EDG_WL_JOBID 'https://wms203.cern.ch:9000/2gABtYdoEjq6R-fNdKH9vg'
JMA 2010/08/30 13:25:20 GATEKEEPER_JM_ID 2010-08-30.13:25:15.0000011355.0000000000 for /DC=es/DC=irisgrid/O=ecm-ub/CN=Ricardo-Graciani-Diaz on 128.142.167.136
JMA 2010/08/30 13:25:20 GATEKEEPER_JM_ID 2010-08-30.13:25:15.0000011355.0000000000 mapped to lhcbpi01 (71001, 2056)
JMA 2010/08/30 13:25:20 GATEKEEPER_JM_ID 2010-08-30.13:25:15.0000011355.0000000000 has GRAM_SCRIPT_JOB_ID 7416345.stro.nikhef.nl manager type pbs
JMA 2010/08/30 13:25:20 GATEKEEPER_JM_ID 2010-08-30.13:25:15.0000011355.0000000000 JM exiting

Now you know under whose credentials the job entered the system:

/DC=es/DC=irisgrid/O=ecm-ub/CN=Ricardo-Graciani-Diaz

You know which system submitted the job to gazon:

gazon:~> host 128.142.167.136 
136.167.142.128.in-addr.arpa domain name pointer wms203.cern.ch.

and you know what the "grid jobID" is:

EDG_WL_JOBID 'https://wms203.cern.ch:9000/2gABtYdoEjq6R-fNdKH9vg'