excessive syscalls writing Measurement Sets

[d3v-null]

There's something horribly wrong with the measurement set writing via rubbl: pkgw/rubbl#226

wget https://projects.pawsey.org.au/birli-test/1061312152_20130823165634_gpubox12_01.fits
wget https://projects.pawsey.org.au/birli-test/1061312152.metafits
docker run -v${PWD}:${PWD} -w${PWD} --entrypoint strace mwatelescope/mwa-demo:latest --summary birli -m 1061312152.metafits -M test.ms 1061312152_20130823165634_gpubox12_01.fits

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ------------------
 34.10    6.543173          19    337640           lseek
 32.18    6.174975          45    137093           write
 32.06    6.150524          30    202215           read
  0.74    0.142350        8896        16           futex
  0.22    0.042053          31      1354        65 newfstatat
  0.19    0.037000          26      1415      1415 readlinkat
  0.14    0.026273          47       553       106 openat
  0.09    0.017046          38       447           close
  0.04    0.007591          18       413           fcntl

for comparison, here is uvfits:

docker run -v${PWD}:${PWD} -w${PWD} --entrypoint strace mwatelescope/mwa-demo:latest --summary birli -m 1061312152.metafits -u test.uvfits 1061312152_20130823165634_gpubox12_01.fits
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ------------------
 79.52    0.474542          37     12656           write
 12.30    0.073403        4893        15           futex
  2.69    0.016075          82       195           read
  1.14    0.006818          28       240           mmap
  0.99    0.005905          45       130        44 openat
  0.72    0.004310          19       222           ioctl

Other software like DP3 does not have these issues writing measurement sets.

[gsleap]

This backs up what I see in my standard Birli test of a specific obsid which I run birli on 2 times a day 12pm and 12am once for uvifts output and another for ms output, but using the same input data and birli output settings.

As you can see the write duration and overall duration for ms is at best 8x slower than uvfits, and at worst just under 50x slower!

Mind you this is on a lustre filesystem, but maybe that is just exacerbating the underlying rubbl ms writing issue.