The return of LHCb at Glasgow

After weeks of investigating and debugging our LHCb transfer issue at Glasgow we have finally fixed it. So ..... spill the beans I hear you cry.

Well in short, we had an iptables rule on the INPUT filter of the NAT that was dropping strangely behaving gridftp connections. This was relaxed and allowed inbound connections to be established. This has solved the issue and we still have the protection of the campus firewall for security.

Strangely behaving gridftp connections, what does that mean? Well, transfers that had failed to work first time seemed to get into an unknown state and transfer no bytes, with many RETRY packets and no FIN packet. It appears that these connections were trying to establish inbound connections. These were then dropped by a REJECT within our iptables.

Moral of the story is, if you can get external IP's for your worker nodes, use them. NAT'ing just adds complexity especially when dealing with GLOBUS.

The full story if you are interested ....

Problem: LHCb don't use FTS. They use direct outbound gridftp transfers of job outputs. Jobs on WN's transfer results, using the lcg-utils tools, at the end of the job to CERN and failover to various T1's if there is an issue with the CERN transfer. LHCb have seen a large failure rate with around 50% of gridftp/lcg-cp transfers failing at Glasgow. Brunel, Sheffield and Lancaster have been affected with the same issue although to a lesser extent. Failure rates at the other sites are much less at around 2-3%. We see the initial transfer timing out, failing over to a T1, this sometimes works and sometimes fails over to another T1 and so on. Why has this not been seen sooner? Well this has actually been there since day dot but DIRAC masked the return code of the failure. A new version of DIRAC catches the fail-overs and are killed by their watchdog. Thus bringing this issue to the surface.

Investigation: Glasgow looks like this WN's-> NAT->CAMPUS FIREWALL->WORLD. We managed to recreate the issue with a simple transfer test from varying amounts of WN's to test SRM end-points. This recreated the issue and we saw a 50% failure rate across various SRM implementations, in particular CASTOR, DCACHE, STORM. However, DPM transfers were 100% successful. Failed transfers manifested themselves are lcg-cp: timed out or lcg-cp: error on send. We repeated these tests using various VO's and got similar results so we did not think it was VO related. We monitored the connections though our NAT and asked the firewall team to check if any outbound ports were blocked, they were not. The GLOBUS_TCP_PORT_RANGE at Glasgow was set to a specific known open port range for inbound connections but this does not matter in this case of outbound connections. To be on the safe side we set GLOBUS_TCP_SOURCE_RANGE for outbound connections through our NAT. As we expected this did not make a difference. After discussion with other sites we checked client libraries, OS and network. One thing that did crop up was the use of NAT.

The final test was 100 simultaneous transfers from one node via the NAT. We saw a 50% failure rate. We repeated this test but this time with an external address and no NAT routing. This was 100% successful over 3 attempts. Quickly repeated tests did show some failures but this was probably the firewall dropping connections. Therefore, we were able to clearly identify the NAT as being the issue. We tried tweaking TCP settings on the NAT i.e. tcp_fin_timeout, tcp_tw_reuse, tcp_tw_recycle, tcp_keepalive_time with no success. The iptables rules themselves seemed sensible but we were still dropping 50% of the connections.

We then moved to tcpdumping the tcp packets (SYN and FIN) from the internal (eth0) device and compared it to a tcpdump of the external (eth1) device. You could clearly see the control channels opening, data channels opening, transfers and then around 50% of the transfers sending retry packets and never sending a FIN. It looked like something was being blocked.

A closer look at the iptables rules identified an entry on the INPUT filter that could be the culprit. Further up the chain we were allowing RELATED,ESTABLISHED as you would expect. Then we had a -A INPUT -i eth1 -p tcp -m tcp -j REJECT --reject-with tcp-reset. It appears this entry caused attempts to re-establish the connection to fail (possibly by blocking the initial packet from the destination, erroneously considering it not to count as ESTABLISHED any more). Very strange behaviour indeed. In the plus side we generally use the campus firewall to protect us from unwanted traffic rather than our own iptables rules, so we have relaxed the INPUT filter and guess what, near 100% transfer success.

LHCb Production Failures

Over the last week we have been investigating why we have around 50% failure rate with LHCb jobs. All seem to be failing with the same issue which is sometimes not being able to copy their results back to the Tier 0 or subsequent fail-over Tier 1 site. This is not strictly just a Glasgow issue and it has affected Sheffield and Brunel, although the issue appears to have gone away from Brunel.

We have tried pretty much everything, as simple lcg-ls and lcg-cp actually work from the worker nodes so its not a certificate issue. The failures are not particular to a CE. Nothing changed at our site prior to the failure and LHCb say nothing changed at their end. In fact they have sites in the UK such as Manchester working fine.

None of the failures correspond to a particular set of worker nodes which might indicate NAT issues for us as we split our odd and even nodes through separate NAT's. However, it does look like network contention at some point in the process as we see either broken pipes or timeouts in the logs direct from Globus.

2010-03-04 04:04:56 UTC dirac-jobexec.py ERROR: SRM2Storage.__putFile: Failed to put file to storage. file:/tmp/8230840/CREAM603030715/7472318/00005987_00009161_3.dst: globus_xio: System error in writev: Broken pipe
2010-03-04 04:04:56 UTC dirac-jobexec.py ERROR: globus_xio: A system call failed: Broken pipe

The only constant so far is that their appears to be a 50% failure rate from failed uploads which happens consistently from submissions from DIRAC.

Its certainly a puzzler and we are fast running out of ideas!

NATs Maxing Out

During our investigation of our LHCb failures we noticed that our number of conntrack entries on our two NAT hosts were in fact being totally used up i.e. all 43200! By looking at /proc/net/ip_conntrack we noticed that most of the connections were in fact udp DNS lookups by Camont jobs. We also noticed that we had not changed the default timeouts, 32768 for tcp and 3600 for udp. This was probably the reason they were being used up. So we have tweaked the timeouts and increased the maximum.
So our new NAT settings look like this:

/etc/sysctl.conf
original values of 43200, 32768, 3600 respectively.
net.ipv4.netfilter.ip_conntrack_tcp_timeout_established = 21600
net.ipv4.netfilter.ip_conntrack_max = 65536
net.ipv4.netfilter.ip_conntrack_udp_timeout = 30

Now out NAT's look much healthier. Only problem - it didn't help with LHCb productions jobs not being able to upload their results back to CERN. Back to the drawing board.

Edinburgh as an LHCb Tier-1?

I've just been accused (jokingly, I hope) of trying to turn Edinburgh into LHCb's 7th Tier-1. The attached plot shows the recent data transfers that I have been running into our dCache. The rates are good (~35MB/s), but not particularly special. However, against a background of zero, it certainly made LHCb jump up and take notice ;) Maybe this will convince them that Tier-2s really can be used for analysis jobs...

I should note that during these transfers one of the dCache pools was about to melt (see below). I've since reduced the max number of movers on each pool to something more reasonable. For the tests, I created a small application that spawned ~50 simultaneously lcg-cp's that were all transferring files from CERN CASTOR to Edinburgh. Who needs FTS when you've got DIRAC and lcg_utils? Now all I need is someone else's proxy and I'll never be caught... ;) But, on a serious note, I suppose this does show that people can create tools to abuse the system and get round the official FTS channels, which could impact the service for other users.

Job submission with DIRAC

In order to get some "real user" experience of performing physics analysis on the Grid, I have been doing a lot of reading and playing with the LHCb computing software. First of all, there's a lot of it so it takes a while to get to understand what each component does, how they can be linked together, how they are configured and built and how the applications can be run locally or on the Grid to do some real physics.

I was particularly interested in getting some basic jobs running on the Grid, so I quickly started playing with Ganga, the user interface for job configuration and submission. At first I was quite impressed. It was very simple to use Ganga to submit small jobs to the local system, CERN batch or the Grid (via the LHCb DIRAC workload management system). However, a few problems quickly appeared:

1. Jobs were continually failing on the Grid due to poorly configured software installations on the sites. Missing libraries was the main source of problems. It also seems that the latest version of Gauss v30r3 (LHCb MC generation) is a bit broken due to a mis-configured path. These things weren't a problem with Ganga as such, but using it meant that another layer had to potentially be debugged.

2. I found bulk job submission was very difficult in Ganga. Writing the python code to loop over the jobs is easy, but the client just couldn't handle the 100's of jobs going through it. It became very slow and eventually just hung. Even just starting up the client is slow. Maybe running on a non-lxplus machine would be better. There were also inconsistencies between the Ganga job monitoring and that reported by DIRAC.

As an alternative, I decided to bypass Ganga and use the DIRAC API directly. This proved to be quite successful, being much faster for bulk submission. I put together some notes on this, which can be found here:

http://twiki.cern.ch/twiki/bin/view/Main/LHCbEdinburghGroupDIRACAPI

Using DIRAC didn't help with the site mis-configurations (although it is easy to get the job output and check the log files for problems), but I found it a more efficient way of working. I'll try again with Ganga once I understand better the problems that keep on appearing on the Grid.

From my brief foray into running jobs on the Grid, it appears that Ganga/DIRAC do insulate users from malfunctioning middleware, however, there are still real problems when it comes to poorly installed software on the sites. From a deployment point of view, maybe this should be taken as encouragement, as the problem is at the application level and not so much with the middleware. I think we would need to do a more systematic study to find this out (much like Steve's ATLAS jobs).

What is needed is better testing of the sites by through VO-specific SAM tests. This information then has to be fed back into DIRAC (or whatever) so that mis-configured sites can be ignored until their problems are resolved. User will then find running jobs on the Grid a much easier and pleasant experience.

LHCb Stuck Jobs

Coincidentally with drafting the stalled jobs document, we got 23 stalled LHCb jobs last Friday. These jobs had consumed about a minute of CPU then just stopped.

I reported them to lhcb-production@cern.ch and the response from LHCb was very swift and helpful. We did quite a bit of debugging on them - although in the end we had to confess that exactly why these ones had stalled was something of a mystery. At first LHCb thought that NFS might have gone wobbly at our end, so the jobs got stuck reading the VO software. From what I could see this was unlikely, and when NIKHEF, RAL and IN2P3 reported similar problems we were off the hook.

Some useful tools for stuck jobs:

• lsof - see what file handles are open
• strace - what's the job doing right now
• gdb - attach a debugger to the code
  

In fact, a lot of simple diagnostics also help: what's in the job's running directory. What STDOUR/STDERR has been produced to far, etc.

When these jobs are killed it's helpful to poke the stalled process - that way information gets back to the VO. A qdel will see the outputs all lost and the job resubmitted elsewhere, which is far less helpful.

In the end, whatever the bug is, it's down at the 10^-6 level!

Thanks to LHCb for being so responsive.

I also must take my hat off to Paul and his MonAMI torque plugin. His live efficiency plots for the batch system queues made spotting this very easy. In the past this sort of thing would have been noticed on a very hit or miss basis.

Health and Efficiency

As part of investigating the problems of stalled jobs, I have plotted Wall vs. CPU time for ATLAS and LHCb on our cluster.

LHCb jobs are generally quite efficient (as evidenced by their 93% efficiency from the EGEE accounting pages). What's interesting is seeing the cluster of jobs at 11 and 22 hours of CPU time, with a smear in wall clock from prefect efficiency to ~50% (data management stikes again?).

ATLAS jobs have a far more variable profile, with many more short jobs of high efficiency, with a more general, and flatter line out to lower efficiencies. There's a very distinct line of problematic jobs (the spike on the tail).

It seems really that with our new fast CPUs our queue times are really much too long (inherited from the old cluster, if I remember). LHCb and ATLAS both seem happy for queues to be reduced from 96/100 hours to 36/36 hours.

Edinburgh finally got pushed over the edge by the LHCb jobs - the CE became unstable and the BDII failed.

The GGUS ticket is https://gus.fzk.de/pages/ticket_details.php?ticket=11192&from=allt.

There's no evidence that Edinburgh ever published an annomolously low ERT which would have sucked these jobs in, so I think it must have been an LHCb problem:

VO Software

We got a ticket from LHCb about a missing RPM on our reinstalled cluster.

It's long been my opinion that this needs to be addressed by having VO specific meta-packages: lcg-lhcb RPMs with all of their dependencies. Otherwise it's almost impossible to find out what a VO needs. A manual list on the CIC portal would be a step forward, but it's too much to do this by hand for multiple VOs.