"Oh no! Not again..."

After being all enthusiastic that the gSOAP errors had been nailed, we failed two SE tests in the last 24 hours. Exactly the same issue as before.

As this error message is so vague it looks like lcg-rollout is our only hope.

I note in passing that Glasgow has one of the most reliable SEs in the UK for ATLAS (2.1% job loss, only beaten by Oxford who have 0.8%; UK average in Q3 was 8% loss) so this is particularly galling.

Shouldn't we be making the results as seen by our real customers rather more important than a once an hour stab in the dark from ops?

Death to gSOAP...

Even after the successful upgrade of DPM we started to get plagued again by SAM test failures with the generic failure message:

httpg://svr018.gla.scotgrid.ac.uk:8443/srm/managerv1:
CGSI-gSOAP: Error reading token data header: Connection closed

This time they came principally from the SE test, instead of from the CE-rm test.

For a while I wondered if there was a DNS problem, but this seemed unlikely for two reasons:

1. Durham use the .scotgrid.ac.uk domain, but they don't see errors.
2. We see the connection in the srmv1 logs, so the host can be resolved.

Then I started to wonder if there was a CRL problem as we occasionally get CRL warnings from SAM WN tests. We have an optimised CRL download system at Glasgow - the CE downloads CRLs as normal, then the remaining nodes mirror the CRLs from the CE. This means we make 1 outbound connection every 6 hours, instead of 150, which seems eminently sensible on a large cluster. However, the default crons for the nodes are 6 hours to process CRLs, which means that CRLs could be up to 12 hours old, in the worst case, on client nodes.

On this suspicion I changed the CE configuration to download CRLs every hour and for the clients do download these from the CE every 4 hours.

I made this change on Friday and, so far, we haven't seen the error again.

My eternal complaint with X509/openssl is why the error is reported as "CGSI-gSOAP: Error reading token data header: Connection closed" and not "CGSI-gSOAP: Error reading token data header: Connection closed [CRL for DN BLAH out of date]".

Is that so very hard to do?

chew 'em up, spit 'em out...

Failed SAM tests all day. When I checked the logs they'd all run on
node006. Logged in and...

Oct 11 16:58:40 node006 smartd[3163]: Device: /dev/hda, 1 Currently unreadable (pending) sectors
Oct 11 17:28:40 node006 smartd[3163]: Device: /dev/hda, 1 Currently unreadable (pending) sectors
Oct 11 17:58:41 node006 smartd[3163]: Device: /dev/hda, 1 Currently unreadable (pending) sectors
Oct 11 18:00:14 node006 pbs_mom: Invalid argument (22) in mem_sum, 5754: get_proc_stat
Oct 11 18:13:23 node006 pbs_mom: Invalid argument (22) in resi_sum, 8121: get_proc_stat
Oct 11 18:28:40 node006 smartd[3163]: Device: /dev/hda, 1 Currently unreadable (pending) sectors
Oct 11 18:58:40 node006 smartd[3163]: Device: /dev/hda, 1 Currently unreadable (pending) sectors
Oct 11 19:28:40 node006 smartd[3163]: Device: /dev/hda, 1 Currently unreadable (pending) sectors
Oct 11 19:44:32 node006 pbs_mom: Invalid argument (22) in resi_sum, 9482: get_proc_stat

Took it offline and immediately we're back.

It's just amazing that one bad node in 142 can kill off a whole site for SAM... it took out 3626 jobs in less than 12 hours.

This is really torque's fault - it should have a bad node sensor at the batch system level.

(As an aside it didn't affect ATLAS production at all, because if a node is so bad that the pilot doesn't start then it never pulls in a real job.)

opendns to the rescue

Glasgow, Edinburgh and Durham suffered SAM failures today due to the scotgrid BDII going AWOL. Actually the BDII itself was OK, the problem was caused by the campus DNS servers taking ages to respond and the LDAP query timing out before they responded.

Cue one quick switchover to OpenDNS servers instead.

Worth scribbling on a sticky note - the 2 nameserver IPs are 208.67.222.222 and
208.67.220.220

Update to the above:
OpenDNS don't return NXDOMAIN for non-existent domains, such as .beowulf.cluster -- This can break your installer horribly (as we discovered at glasgow) if you're expecting things to check which is the right address)

However as we're using dnsmasq you can get round this by flagging the 'helpful' opendns guide addresses as bogus:

ie setup your /etc/dnsmasq.conf

no-resolv
server=208.67.222.222
server=208.67.220.220
bogus-nxdomain=208.69.34.132

This then gives the expected results:

svr031:~# dig www.flarble.co.uk

; <<>> DiG 9.2.4 <<>> www.flarble.co.uk
;; global options:  printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NXDOMAIN, id: 10483
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;www.flarble.co.uk.             IN      A

;; Query time: 105 msec
;; SERVER: 10.141.255.254#53(10.141.255.254)
;; WHEN: Fri Oct 31 09:52:00 2008
;; MSG SIZE  rcvd: 35


compared to...
svr031:~# dig www.flarble.co.uk @208.67.222.222

; <<>> DiG 9.2.4 <<>> www.flarble.co.uk @208.67.222.222
; (1 server found)
;; global options:  printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 24219
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;www.flarble.co.uk.             IN      A

;; ANSWER SECTION:
www.flarble.co.uk.      0       IN      A       208.69.34.132

;; Query time: 11 msec
;; SERVER: 208.67.222.222#53(208.67.222.222)
;; WHEN: Fri Oct 31 09:52:13 2008
;; MSG SIZE  rcvd: 51

nanocmos + lcas = FAIL

While working on an unrelated issue on svr021 I noticed an edg-mkgridmap error in the logfile

Aug 29 05:28:14 svr021 edg-mkgridmap[6693]: voms search(https://svr029.gla.scotgrid.ac.uk:8443/voms/vo.scotgrid.ac.uk/services/VOMSCompatibility?method=getGridmapUsers): Internal Server Error

Mentioned to mike who promptly went and fixed the issue, only to discover 30 mins later we're failing SAM tests - LCAS voms plugin had once again gone fubar and caused globus-gatekeeper to segfault

Aug 29 12:14:41 svr021 GRAM gatekeeper[662]: Authenticated globus user: [DN REMOVED]
Aug 29 12:14:41 svr021 GRAM gatekeeper[663]: Authenticated globus user: [DN REMOVED] Aug 29 12:14:41 svr021 kernel: globus-gatekeep[662]: segfault at 0000000000000046 rip 0000000000b86259 rsp 00000000ffff9d98 error 4
Aug 29 12:14:41 svr021 kernel: globus-gatekeep[663]: segfault at 0000000000000046 rip 0000000000b86259 rsp 00000000ffff9d98 error 4


the globus gatekeeper log has a bit more info:
TIME: Fri Aug 29 12:14:41 2008
PID: 663 -- Notice: 5: Authenticated globus user: [DN REMOVED]
lcas client name: [DN REMOVED]
LCAS 0:
LCAS 1: Initialization LCAS version 1.3.7
allowing empty credentials
LCAS 2: LCAS authorization request
LCAS 0: lcas_userban.mod-plugin_confirm_authorization(): checking banned users in /opt/glite/etc/lcas/ban_users.db
LCAS 0: lcas_plugin_voms-plugin_confirm_authorization_from_x509(): Did not find a matching VO entry in the authorization file
LCAS 0: 2008-08-29.12:14:41 : lcas_plugin_voms-plugin_confirm_authorization_from_x509(): voms plugin failed
LCAS 0: lcas.mod-lcas_run_va(): authorization failed for plugin /opt/glite/lib/modules/lcas_voms.mod
LCAS 0: lcas.mod-lcas_run_va(): failed
LCAS 0: lcas_plugin_voms-plugin_confirm_authorization_from_x509(): Did not find a matching VO entry in the authorization file
LCAS 0: 2008-08-29.12:14:41 : lcas_plugin_voms-plugin_confirm_authorization_from_x509(): voms plugin failed
LCAS 0: lcas.mod-lcas_run_va(): authorization failed for plugin /opt/glite/lib/modules/lcas_voms.mod
LCAS 0: lcas.mod-lcas_run_va(): failed
JMA 2008/08/29 12:14:45 GATEKEEPER_JM_ID 2008-08-29.11:14:39.0000014519.0000000000 JM exiting

As before, commenting out the lcas_voms.mod in /opt/glite/etc/lcas/lcas.db allows it to work, at the expense of losing VOMS roles.

We've got it working using the voms_mod at the moment by altering the ACLs on the VOMS server (svr029) for nanocmos. Now to try and debug the lcas plugin failure

CE-sft-lcg-rm-rep fail

Ho Hum - After sorting out the gatekeeper, we still get a sam fail. Wait a minute...

Checking replication to Central SE (lxdpm101.cern.ch)

Replicate the file from the default SE to lxdpm101.cern.ch

+ lcg-rep -v --vo ops -d lxdpm101.cern.ch lfn:sft-lcg-rm-cr-node114.beowulf.cluster.080827052321.475531
Using grid catalog type: lfc
Using grid catalog : prod-lfc-shared-central.cern.ch
Source SE type: SRMv1
Destination SE type: SRMv1
httpg://lxdpm101.cern.ch:8443/srm/managerv1: No space left on device
lcg_rep: No space left on device
+ result=1
+ set +x

No space on device? grr - don't these people have monitoring ;-)

gatekeeper AWOL

Glasgow suffered 3-4 hours CE outage this evening as the globus-gatekeeper on svr021 had gone AWOL. we suffered a few SAM tests before I twigged that the 'connection refused' was coming from our end - 'service globus-gatekeeper restart' nobbled that but not until we'd failed 7 sam tests. Damn.

SAM Failures across scotgrid: Someone else's problem

All 3 scotgrid sites have just failed the atlas SAM SE tests (atlas_cr, atlas_cp, atlas_del) as have quite alot of the rest of the UKI-* sites.

Once again this isn't a Tier-2 issue but an upstream problem with the tests themselves


ATLAS specific test launched from monb003.cern.ch
Checking if a file can be copied and registered to svr018.gla.scotgrid.ac.uk

   ------------------------- NEW ----------------
srm://svr018.gla.scotgrid.ac.uk/dpm/gla.scotgrid.ac.uk/home/atlas/
+ lcg-cr -v --vo atlas file:/home/samatlas/.same/SE/testFile.txt -l lfn:SE-lcg-cr-svr018.gla.scotgrid.ac.uk-1219649438 -d srm://svr018.gla.scotgrid.ac.uk/dpm/gla.scotgrid.ac.uk/home/atlas/SAM/SE-lcg-cr-svr018.gla.scotgrid.ac.uk-1219649438
Using grid catalog type: lfc
Using grid catalog : lfc0448.gridpp.rl.ac.uk
Using LFN : /grid/atlas/dq2/SAM/SE-lcg-cr-svr018.gla.scotgrid.ac.uk-1219649438
[BDII] sam-bdii.cern.ch:2170: Can't contact LDAP server
lcg_cr: Host is down
+ out_error=1
+ set +x
   -------------------- Other endpoint same host -----------

Nagios, nagios, where are you?

Nagios seems not to be sending us alarms properly on SAM test failures (we had 2 yesterday - one for an internal SAM problem and the other for an SRMv1 timeout issue).

Andrew is investigating.

ECDF SAM Tests Fixed

Sam managed to fix SAM last week. It turned out that the two CEs were interfering with each other in the samsgm account area and producing corrupted GASS caches. It's still a bit of a mystery as to why this happened - shared accounts for *sgm has been normal (if not best) practice for ages. However, it's being worked around and the site is up and stable again.

Publish and be damned...

It all went pear shaped yesterday as information publishing fell over on the SE. It seems when I quickly "fixed" the DPM information provider script to get the correct hostname I forgot to chomp() the output from "hostname -f". So the hostname variable had a trailing newline which corrupted the information system. The BDII logs started to throw errors like "First line of LDIF entry does not begin with 'dn:' at /opt/glite/libexec/glite-info-generic line 17".

Unfortunately the BDII then considered the whole of the SE information package corrupt (rather than just that provider's output) and our SE promptly dissappeared from the information system with the attendent RM test failures.

This situation then persisted for most of the day until Andrew noticed it "by eye". So we had another failure - nagios didn't send an alarm properly when we started to fail. If that had happened it would have been fixed in a hour, but instead we were failing for 8 hours.

From the dizzy heights of SAM perfection we fell to 98% for the month, 95% for the week. It wasn't quite hubris, but it was ironic that I was blogging about Glasgow's reliability at the very moment we were broken.

At the moment I have removed the info provider for tokens, and I will more carefully put it back on Tuesday.

Problems up north

We have two major problems in ScotGrid right now:

ECDF: Have been failing SAM tests for over a week now. The symptom is that the SAM test is submitted successfully, runs correctly on the worker node, but then job outputs never seem to get back to the WMS, so eventually the job is timed out as a JS failure. As usual we cannot reproduce the problem with dteam or ATLAS jobs (in fact ATLAS condor jobs are running fine) so we are hugely puzzled. Launching a maual SAM test throught the CIC portal doesn't help because the test gets into the same state and hangs for 6 hours - so you cannot submit another one. Sam has asked for more network ports to be opened to have a larger globus port range, but the network people in Edinburgh seem to be really slow in doing this (and it seems it is not the root cause anyway).

Durham: Have suffered a serious pair of problems on their two SE hosts. The RAID filasystem on the headnode (gallows) was lost last week and all the data is gone. Then this week the large se01 disk server suffered an LVM problem and we can no longer mount grid home areas or access data on the SRM. Unfortunately Phil is on holiday, David is now off sick and I will be away on Monday - hopefully we can cobble something together to get the site running on Tuesday.

Thankfully, dear old Glasgow T2 is running like a charm right now (minor info publishing and WMS problems aside). In fact our SAM status for the last month is 100%, head to head with the T1! Fingers crossed we keep it up.

It's all gone 'orribly wrong

OK - My bad. I spotted we failed a sam test yeterday (got a mail from the automated alert) - didn't realise it doesn't send multiple ones if you keep failing....

Am sure Graeme will post more but we'd filled up / (as /var wasn't on a separate partition - it is now, and a nice healthy 30G) on the CE. Puzzlingly nagios hadn't bothered to alert that we'd gone warning at 8% free or critical at 4% free and was "OK - /0 free"

case sensitivity in check_disk: -w is for disk space, -W is for inodes. grr. Typo-tastic. I lowercased the offending config and let cfengine ripple it out. While it did so I noticed cfengine restarted ntpd on the 3 nat boxes (that also act as the timeservers for the cluster) - somehow it was copying both a standard then a local /etc/ntp.conf into place each time and restarting as planned on a new config file.

my bad - we use class 'natboxes' for the group and I'd specified any.!(master|nat):: changing it to any.!(master|natboxes) worked fine - no restart since and none of the workernodes are seeing any upstream timeservers on INIT or LOCAL

Grid-Monitoring Nagios tests

Finally (after a long interval) I reinvestigated getting the LCG Grid Service Monitoring Working Group nagios tests installed at Glasgow.

I had tried once before, but it needed nagios on our UI. This time I added a UI to our nagios host (nice n simple - simply added the hostname into the relevant UI group in cfengine). Works fairly well - I've got it installed and polling the SAM tests via the sam-API and picking up the results. I still need to get certificate proxy renewals working, and merge the records together with our existing definitions for the hosts (we use non-qualified names, the wlcg.cfg used FQDNs)

As the screen shot shows - We've already got a lot of green - and if we can nail the cert problems I'll switch it over to use the normal notification system

First Jobs Run at ECDF

Finally, after several months of anguish, SAM jobs are running at ECDF! Note that for the moment they fail replica management tests (there was little point in putting effort into the DPM while the CE was so broken), but at last we're getting output from SAM jobs coming back correctly.

The root cause of this has been networking arrangements which were preventing the worker nodes from making arbitrary outbound connections. Last week we managed to arrange with the systems team to open all ports >1024, outbound, from the workers. Then it was a matter of battering down each of the router blocks one by one (painfully these seemed to take about 2 days each to disappear).

Testing will now continue, but we're very hopeful that things will now come together quickly.

WLCG Workshop

There's a lot on the agenda page, and Jamie's CHEP summary talk is a useful round up, but here are my highlights:

• GDB consider services necessary for WLCG operations to basically have been delivered, but not fully deployed (far less extensively tested and battle hardened). My own feeling is that in the integration and mutual interaction (e.g., VOMS and SRM v2.2) of all these services with WLCG production we've still a long way to go.
• In their pre-acceptance tests, the gLite-CE and the CREAM CE did about as well as one another. Given that CREAM has a simpler internal architecture and is more standards compliant it has been chosen over the gLite-CE (which is "no longer being developed"). It's anticipated that CREAM will be first delivered to production in the New Year, but that in total it's anticipated to take about a year from now before it's fully hardened, sites have experience in running it and the YAIM configuration is fully working - oh! just around data taking time ;-) However... this seems rather sensible to me to have settled on the one CE, rather than the unsatisfactory situation of having 2 on the go. Pity the poor folk who put effort into actually running gLite CE as a service!
• Operations: We still have trouble sharing knowledge. 2007 was the year of the grid blog, but only a fool would pretend that will solve all our problems. I proposed a wiki plugin, where articles less than a month old would be black on white, with the text gradually fading to paler shades of grey the longer the article was unrevised. When it reaches white the article is expired!
• SAM is the test framework for everyone. Experiments should publish their tests into SAM so that it's a one-stop-shop for sites' status.
  
• Monitoring: We look forward to a proper demo of the SAM/nagios framework at EGEE.
• SRM v2.2: Confusion still abounds. What spaces to ATLAS want at T2s? Not even they know yet...
• Dress Rehersals: Lots going on for every experiment. See their presentations for more details.
• Common Computing Readiness Challenge (CCRC): There's an urgent need to tests the whole of the Accelerator->T0->T1->T2 chain for all experiments before real data flows. This will probably happen in February (limited, because not everything will be ready) and in May (really, has to work!). I expect this to be quite a big deal for everyone, especially the May round.
  
• ATLAS Session: Good information on Production Dashboard, DDM dashboard and operations (with cool http queries).
  

Bad, bad, biomed....

A very flaky day - we had a biomed user throw jobs into the system which were trashing workernodes by filling up /tmp. This caused lots of nodes to get into a weird state where they seemed to run our of memory (ssh and ntp nagios alarms firing). Jobs couldn't start properly on these nodes, so they became black holes: one of our local users lost 47 of 50 jobs, another lost 124 of 150.

We then started to fail SAM tests, drop out of the ATLAS BDII, Steve's tests then couldn't resource match us, and so on. Bad day.

It took quite a few hours to sort out the mess, and a further few hours to stabalise the site.

Our GGUS ticket names and shames.

It's a very different ball game on the grid - we have 6000+ users who can submit jobs, and it's not hard to kill a worker node. The torque generally handles this badly and all hell breaks loose.

Action plan:

1. Nagios alarms on WN disk space
2. Group quotas on job stratch area

SAM Gets Downtime Wrong?

Durham were in downtime from Wednesday -> Thursday, but SAM thinks they were in downtime from Thursday -> Friday. Doubtless this happened because I made the initial mistake (out by 1 day!), then edited the downtime to bring it forward. But SAM did not pick up the change.

I've raised a GGUS ticket - after all I'm always editing downtimes!

SAM tests changed VOMS Role (without warning!)

We, and a large fraction of the rest of the grid, started to fail replica management tests late on Friday night. At first I thought it must be a catalog problem at cern, so I raised a ticket. However, it turned out that what had actually happened was that the VOMS role used to submit the SAM tests had changed. This caused DPM to map the SAM tester DN into a different group - who then did not have permission to write into the default generated directory for lcg-cr.

This change was made completely unannounced, and I suspect without any real thought as to the implications for sites using DPM 1.6.3 and earlier.

Maarten Litmath helpfully posted a fix-up script on LCG-ROLLOUT, which uses ACLs to grant suitable privileges to lcgadmin and production roles for each supported VO, which I applied to Glasgow and Durham at about midnight last night (I was surely violating cardinal rules of sysadmining, but I couldn't see how it would cause harm - and this time I got away with it). This did fix the problem.

I'm really annoyed that this though. Changes like this should never, ever be made on a Friday! (It seemed the change actually came through at ~10am, but didn't break until midnight, when the next YYYY-MM-DD directory needed to be created.) In addition several people have commented that the fix is to upgrade to DPM 1.6.4 - despite the fact that this is broken in gLite 3.0r25 in two significant ways!

Grrrr. I just hope they don't ask us to explain these SFT failures - they shall have a piece of my mind... (I sound just like my Mum, when she was annoyed - see what the grid's doing to me!).

Happy New Year ScotGrid!

Despite running unattended over the Christmas holidays, ScotGrid sites were by-and-large available.

From 2006-12-20 to 2007-01-03 SAM status for each site was:

ScotGRID-Edinburgh:  SAM test pass rate 241/338 = 71.3%
                    (Failures: JS 3, RM 94)
scotgrid-gla:        SAM test pass rate 324/338 = 95.8%
                    (Failures: JS 4, RM 10)
UKI-SCOTGRID-DURHAM: SAM test pass rate 318/338 = 94.1%
                    (Failures: JS 6, RM 14)
UKI-SCOTGRID-GLA:    SAM test pass rate 328/338 = 97.0%
                    (Failures: JS 1; RM 9)

Looking at the JS and RM failures for everyone except Edinburgh these seem to be at the level of grid flakiness caused by higher level services failing or timing out (e.g., RM test times out, BDII fails to respond, etc.). So our only significant problem was issues with Edinburgh's dCache, which did seem to be unreliable.

Any comments Greig? Did you have to intervene?