glencoesoftware/bioformats2raw

conversion fails midway through big h5 file

Closed this issue · 9 comments

I'm trying to convert https://idr.openmicroscopy.org/webclient/?show=image-9846152 (requested at https://forum.image.sc/t/converting-other-idr-images-into-public-zarr/44025/13) to OME-NGFF.

Working on pilot-zarr1-dev I have downloaded the files to /data/idr0048 with

rsync -av  -e "ssh -A idr-pilot.openmicroscopy.org ssh" "idrtesting-omeroreadwrite:/uod/idr/filesets/idr0048-abdeladim-chroms/20191119-ftp/" -P .
(base) [wmoore@pilot-zarr1-dev idr0048]$ ls -alh
total 48G
...
-rw-rw----. 1 wmoore idrnfs    48G Nov 19  2019 WB.h5
-rw-rw----. 1 wmoore idrnfs   2.3K Nov 19  2019 WB.xml
-rw-rw-r--. 1 wmoore wmoore   8.2K Jan 12 16:45 .WB.xml.bfmemo

Checked that the downloaded files match what's on IDR:

$ cksum
3758472695 51049420472 WB.h5
742400829 2334 WB.xml

Running in a terminal screen, I see:

$ bioformats2raw --version
Version = 0.5.0
Bio-Formats version = 6.10.1
NGFF specification version = 0.4

$ bioformats2raw WB.xml 9846152_logging.zarr --debug > /home/wmoore/bf2raw.log
OpenJDK 64-Bit Server VM warning: You have loaded library /tmp/opencv_openpnp2269157708896801230/nu/pattern/opencv/linux/x86_64/libopencv_java342.so which might have disabled stack guard. The VM will try to fix the stack guard now.
It's highly recommended that you fix the library with 'execstack -c <libfile>', or link it with '-z noexecstack'.
Killed

The 3 times I have tried this, I get about the same number of files generated:

$ find 9846152.zarr/ -type f | wc -l
18204
$ find 9846152_a.zarr/ -type f | wc -l
18207
$ find 9846152_logging.zarr/ -type f | wc -l
18199
$ cat 9846152.zarr/.zattrs
{
  "bioformats2raw.layout" : 3
}(base) [wmoore@pilot-zarr1-dev idr0048]$ cat 9846152.zarr/0/.zattrs
{
  "multiscales" : [ {
    "metadata" : {
      "method" : "loci.common.image.SimpleImageScaler",
      "version" : "Bio-Formats 6.10.1"
    },
    "axes" : [ {
      "name" : "t",
      "type" : "time"
    }, {
      "name" : "c",
      "type" : "channel"
    }, {
      "unit" : "pixel",
      "name" : "z",
      "type" : "space"
    }, {
      "unit" : "pixel",
      "name" : "y",
      "type" : "space"
    }, {
      "unit" : "pixel",
      "name" : "x",
      "type" : "space"
    } ],
    "name" : "P_t00000, W_s00_0",
    "datasets" : [ {
      "path" : "0",
      "coordinateTransformations" : [ {
        "scale" : [ 1.0, 1.0, 1.0, 1.0, 1.0 ],
        "type" : "scale"
      } ]
    }, {
      "path" : "1",
      "coordinateTransformations" : [ {
        "scale" : [ 1.0, 1.0, 1.0, 2.0, 2.0 ],
        "type" : "scale"
      } ]
    }, {
      "path" : "2",
      "coordinateTransformations" : [ {
        "scale" : [ 1.0, 1.0, 1.0, 4.0, 4.0 ],
        "type" : "scale"
      } ]
    }, {
      "path" : "3",
      "coordinateTransformations" : [ {
        "scale" : [ 1.0, 1.0, 1.0, 8.0, 8.0 ],
        "type" : "scale"
      } ]
    }, {
      "path" : "4",
      "coordinateTransformations" : [ {
        "scale" : [ 1.0, 1.0, 1.0, 16.0, 16.0 ],
        "type" : "scale"
      } ]
    }, {
      "path" : "5",
      "coordinateTransformations" : [ {
        "scale" : [ 1.0, 1.0, 1.0, 32.0, 32.0 ],
        "type" : "scale"
      } ]
    }, {
      "path" : "6",
      "coordinateTransformations" : [ {
        "scale" : [ 1.0, 1.0, 1.0, 64.0, 64.0 ],
        "type" : "scale"
      } ]
    }, {
      "path" : "7",
      "coordinateTransformations" : [ {
        "scale" : [ 1.0, 1.0, 1.0, 128.0, 128.0 ],
        "type" : "scale"
      } ]
    } ],
    "version" : "0.4"
  } ],
  "omero" : {
    "channels" : [ {
      "color" : "FF0000",
      "coefficient" : 1,
      "active" : true,
      "label" : "Channel 0",
      "window" : {
        "min" : 0.0,
        "max" : 65535.0,
        "start" : 0.0,
        "end" : 65535.0
      },
      "family" : "linear",
      "inverted" : false
    }, {
      "color" : "00FF00",
      "coefficient" : 1,
      "active" : true,
      "label" : "Channel 1",
      "window" : {
        "min" : 0.0,
        "max" : 65535.0,
        "start" : 0.0,
        "end" : 65535.0
      },
      "family" : "linear",
      "inverted" : false
    }, {
      "color" : "0000FF",
      "coefficient" : 1,
      "active" : true,
      "label" : "Channel 2",
      "window" : {
        "min" : 0.0,
        "max" : 65535.0,
        "start" : 0.0,
        "end" : 65535.0
      },
      "family" : "linear",
      "inverted" : false
    } ],
    "rdefs" : {
      "defaultT" : 0,
      "model" : "color",
      "defaultZ" : 45
    }
  }
}

but only the highest resolution directory exists (and looks incomplete):

$ ls 9846152.zarr/0/
0

The log file looks like this (middle repeated section not included):

bf2raw.log
2023-01-17 13:16:21,753 [main] DEBUG loci.formats.ClassList - Could not find loci.formats.in.URLReader
java.lang.ClassNotFoundException: loci.formats.in.URLReader
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)
        at loci.formats.ClassList.parseLine(ClassList.java:196)
        at loci.formats.ClassList.parseFile(ClassList.java:258)
        at loci.formats.ClassList.<init>(ClassList.java:138)
        at loci.formats.ClassList.<init>(ClassList.java:122)
        at loci.formats.ImageReader.getDefaultReaderClasses(ImageReader.java:80)
        at com.glencoesoftware.bioformats2raw.Converter.getBaseReaderClass(Converter.java:2105)
        at com.glencoesoftware.bioformats2raw.Converter.convert(Converter.java:538)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:514)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:109)
        at picocli.CommandLine.executeUserObject(CommandLine.java:1953)
        at picocli.CommandLine.access$1300(CommandLine.java:145)
        at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2352)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2346)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2311)
        at picocli.CommandLine$AbstractParseResultHandler.handleParseResult(CommandLine.java:2172)
        at picocli.CommandLine.parseWithHandlers(CommandLine.java:2550)
        at picocli.CommandLine.parseWithHandler(CommandLine.java:2485)
        at picocli.CommandLine.call(CommandLine.java:2761)
        at com.glencoesoftware.bioformats2raw.Converter.main(Converter.java:2274)
2023-01-17 13:16:21,760 [main] DEBUG loci.formats.ClassList - Could not find loci.formats.in.SlideBook6Reader
java.lang.ClassNotFoundException: loci.formats.in.SlideBook6Reader
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)
        at loci.formats.ClassList.parseLine(ClassList.java:196)
        at loci.formats.ClassList.parseFile(ClassList.java:258)
        at loci.formats.ClassList.<init>(ClassList.java:138)
        at loci.formats.ClassList.<init>(ClassList.java:122)
        at loci.formats.ImageReader.getDefaultReaderClasses(ImageReader.java:80)
        at com.glencoesoftware.bioformats2raw.Converter.getBaseReaderClass(Converter.java:2105)
        at com.glencoesoftware.bioformats2raw.Converter.convert(Converter.java:538)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:514)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:109)
        at picocli.CommandLine.executeUserObject(CommandLine.java:1953)
        at picocli.CommandLine.access$1300(CommandLine.java:145)
        at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2352)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2346)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2311)
        at picocli.CommandLine$AbstractParseResultHandler.handleParseResult(CommandLine.java:2172)
        at picocli.CommandLine.parseWithHandlers(CommandLine.java:2550)
        at picocli.CommandLine.parseWithHandler(CommandLine.java:2485)
        at picocli.CommandLine.call(CommandLine.java:2761)
        at com.glencoesoftware.bioformats2raw.Converter.main(Converter.java:2274)
2023-01-17 13:16:21,761 [main] DEBUG loci.formats.ClassList - Could not find loci.formats.in.ScreenReader
java.lang.ClassNotFoundException: loci.formats.in.ScreenReader
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)
        at loci.formats.ClassList.parseLine(ClassList.java:196)
        at loci.formats.ClassList.parseFile(ClassList.java:258)
        at loci.formats.ClassList.<init>(ClassList.java:138)
        at loci.formats.ClassList.<init>(ClassList.java:122)
        at loci.formats.ImageReader.getDefaultReaderClasses(ImageReader.java:80)
        at com.glencoesoftware.bioformats2raw.Converter.getBaseReaderClass(Converter.java:2105)
        at com.glencoesoftware.bioformats2raw.Converter.convert(Converter.java:538)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:514)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:109)
        at picocli.CommandLine.executeUserObject(CommandLine.java:1953)
        at picocli.CommandLine.access$1300(CommandLine.java:145)
        at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2352)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2346)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2311)
        at picocli.CommandLine$AbstractParseResultHandler.handleParseResult(CommandLine.java:2172)
        at picocli.CommandLine.parseWithHandlers(CommandLine.java:2550)
        at picocli.CommandLine.parseWithHandler(CommandLine.java:2485)
        at picocli.CommandLine.call(CommandLine.java:2761)
        at com.glencoesoftware.bioformats2raw.Converter.main(Converter.java:2274)
2023-01-17 13:16:21,762 [main] DEBUG loci.formats.ClassList - Could not find loci.formats.in.ZarrReader
java.lang.ClassNotFoundException: loci.formats.in.ZarrReader
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)
        at loci.formats.ClassList.parseLine(ClassList.java:196)
        at loci.formats.ClassList.parseFile(ClassList.java:258)
        at loci.formats.ClassList.<init>(ClassList.java:138)
        at loci.formats.ClassList.<init>(ClassList.java:122)
        at loci.formats.ImageReader.getDefaultReaderClasses(ImageReader.java:80)
        at com.glencoesoftware.bioformats2raw.Converter.getBaseReaderClass(Converter.java:2105)
        at com.glencoesoftware.bioformats2raw.Converter.convert(Converter.java:538)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:514)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:109)
        at picocli.CommandLine.executeUserObject(CommandLine.java:1953)
        at picocli.CommandLine.access$1300(CommandLine.java:145)
        at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2352)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2346)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2311)
        at picocli.CommandLine$AbstractParseResultHandler.handleParseResult(CommandLine.java:2172)
        at picocli.CommandLine.parseWithHandlers(CommandLine.java:2550)
        at picocli.CommandLine.parseWithHandler(CommandLine.java:2485)
        at picocli.CommandLine.call(CommandLine.java:2761)
        at com.glencoesoftware.bioformats2raw.Converter.main(Converter.java:2274)
2023-01-17 13:16:21,979 [main] DEBUG c.g.bioformats2raw.Converter - Added extra reader: class com.glencoesoftware.bioformats2raw.PyramidTiffReader
2023-01-17 13:16:21,979 [main] DEBUG c.g.bioformats2raw.Converter - Added extra reader: class com.glencoesoftware.bioformats2raw.MiraxReader
2023-01-17 13:16:21,979 [main] DEBUG c.g.bioformats2raw.Converter - Added extra reader: class com.glencoesoftware.bioformats2raw.BioTekReader
2023-01-17 13:16:21,979 [main] DEBUG c.g.bioformats2raw.Converter - Added extra reader: class com.glencoesoftware.bioformats2raw.ND2PlateReader
2023-01-17 13:16:22,023 [main] DEBUG o.s.nativelib.NativeLibraryUtil - processor is INTEL_64 os.arch is amd64
2023-01-17 13:16:22,023 [main] DEBUG o.s.nativelib.NativeLibraryUtil - architecture is LINUX_64 os.name is linux
2023-01-17 13:16:22,025 [main] DEBUG o.s.nativelib.NativeLibraryUtil - architecture is LINUX_64 os.name is linux
2023-01-17 13:16:22,025 [main] DEBUG o.s.nativelib.NativeLibraryUtil - platform specific path is META-INF/lib/linux_64/
2023-01-17 13:16:22,025 [main] DEBUG o.scijava.nativelib.BaseJniExtractor - mappedLib is libturbojpeg.so
2023-01-17 13:16:22,025 [main] DEBUG o.scijava.nativelib.BaseJniExtractor - URL is jar:file:/home/wmoore/miniconda3/share/bioformats2raw-0.5.0-0/lib/turbojpeg-6.10.1.jar!/META-INF/lib/linux_64/libturbojpeg.so
2023-01-17 13:16:22,025 [main] DEBUG o.scijava.nativelib.BaseJniExtractor - URL path is file:/home/wmoore/miniconda3/share/bioformats2raw-0.5.0-0/lib/turbojpeg-6.10.1.jar!/META-INF/lib/linux_64/libturbojpeg.so
2023-01-17 13:16:22,026 [main] DEBUG o.scijava.nativelib.BaseJniExtractor - Extracting 'jar:file:/home/wmoore/miniconda3/share/bioformats2raw-0.5.0-0/lib/turbojpeg-6.10.1.jar!/META-INF/lib/linux_64/libturbojpeg.so' to '/tmp/libturbojpeg5255053282570603788.so'
2023-01-17 13:16:22,038 [main] DEBUG loci.common.NIOByteBufferProvider - Using mapped byte buffer? false
2023-01-17 13:16:22,052 [main] INFO  loci.formats.ImageReader - BDVReader initializing WB.xml
2023-01-17 13:16:22,053 [main] DEBUG loci.formats.FormatHandler - BDVReader initializing WB.xml
2023-01-17 13:16:22,053 [main] DEBUG loci.formats.FormatHandler - loci.formats.in.BDVReader.initFile(WB.xml)
2023-01-17 13:16:22,075 [main] DEBUG loci.common.services.ServiceFactory - Loaded properties from: services.properties
2023-01-17 13:16:22,076 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.POIService and implementation class loci.formats.services.POIServiceImpl
2023-01-17 13:16:22,077 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.MDBService and implementation class loci.formats.services.MDBServiceImpl
2023-01-17 13:16:22,077 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.JPEGTurboService and implementation class loci.formats.services.JPEGTurboServiceImpl
2023-01-17 13:16:22,077 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface ome.codecs.services.LuraWaveService and implementation class ome.codecs.services.LuraWaveServiceImpl
2023-01-17 13:16:22,078 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.common.services.S3ClientService and implementation class loci.common.services.S3ClientServiceImpl
2023-01-17 13:16:22,078 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.JAIIIOService and implementation class loci.formats.services.JAIIIOServiceImpl
2023-01-17 13:16:22,079 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.WlzService and implementation class loci.formats.services.WlzServiceImpl
2023-01-17 13:16:22,080 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.JHDFService and implementation class loci.formats.services.JHDFServiceImpl
2023-01-17 13:16:22,080 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.NetCDFService and implementation class loci.formats.services.NetCDFServiceImpl
2023-01-17 13:16:22,080 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.EXIFService and implementation class loci.formats.services.EXIFServiceImpl
2023-01-17 13:16:22,081 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.MetakitService and implementation class loci.formats.services.MetakitServiceImpl
2023-01-17 13:16:22,081 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.LuraWaveService and implementation class loci.formats.services.LuraWaveServiceImpl
2023-01-17 13:16:22,082 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.OMEXMLService and implementation class loci.formats.services.OMEXMLServiceImpl
2023-01-17 13:16:22,083 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface ome.codecs.services.JAIIIOService and implementation class ome.codecs.services.JAIIIOServiceImpl
2023-01-17 13:16:22,083 [main] DEBUG loci.common.services.ServiceFactory - Added interface interface loci.formats.services.JPEGXRService and implementation class loci.formats.services.JPEGXRServiceImpl
2023-01-17 13:16:22,244 [main] INFO  loci.formats.FormatHandler - Timepoint :t00000
2023-01-17 13:16:22,244 [main] INFO  loci.formats.FormatHandler - Setup :t00000/s00
2023-01-17 13:16:22,244 [main] INFO  loci.formats.FormatHandler - Site :t00000/s00/0
2023-01-17 13:16:22,245 [main] INFO  loci.formats.FormatHandler - Site :t00000/s00/1
2023-01-17 13:16:22,245 [main] INFO  loci.formats.FormatHandler - Site :t00000/s00/2
2023-01-17 13:16:22,245 [main] INFO  loci.formats.FormatHandler - Site :t00000/s00/3
2023-01-17 13:16:22,245 [main] INFO  loci.formats.FormatHandler - Site :t00000/s00/4
2023-01-17 13:16:22,245 [main] INFO  loci.formats.FormatHandler - Site :t00000/s00/5
2023-01-17 13:16:22,245 [main] INFO  loci.formats.FormatHandler - Site :t00000/s00/6
2023-01-17 13:16:22,245 [main] INFO  loci.formats.FormatHandler - Site :t00000/s00/7
2023-01-17 13:16:22,245 [main] INFO  loci.formats.FormatHandler - Setup :t00000/s01
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/0
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/1
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/2
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/2
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/3
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/4
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/5
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/6
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Site :t00000/s01/7
2023-01-17 13:16:22,246 [main] INFO  loci.formats.FormatHandler - Setup :t00000/s02
2023-01-17 13:16:22,247 [main] INFO  loci.formats.FormatHandler - Site :t00000/s02/0
2023-01-17 13:16:22,247 [main] INFO  loci.formats.FormatHandler - Site :t00000/s02/1
2023-01-17 13:16:22,247 [main] INFO  loci.formats.FormatHandler - Site :t00000/s02/2
2023-01-17 13:16:22,247 [main] INFO  loci.formats.FormatHandler - Site :t00000/s02/3
2023-01-17 13:16:22,247 [main] INFO  loci.formats.FormatHandler - Site :t00000/s02/4
2023-01-17 13:16:22,247 [main] INFO  loci.formats.FormatHandler - Site :t00000/s02/5
2023-01-17 13:16:22,247 [main] INFO  loci.formats.FormatHandler - Site :t00000/s02/6
2023-01-17 13:16:22,247 [main] INFO  loci.formats.FormatHandler - Site :t00000/s02/7
2023-01-17 13:16:23,221 [main] DEBUG loci.formats.FormatHandler - t00000/s00/0/cells/
2023-01-17 13:16:23,495 [main] DEBUG loci.formats.FormatHandler - t00000/s00/1/cells/
2023-01-17 13:16:23,551 [main] DEBUG loci.formats.FormatHandler - t00000/s00/2/cells/
2023-01-17 13:16:23,567 [main] DEBUG loci.formats.FormatHandler - t00000/s00/3/cells/
2023-01-17 13:16:23,572 [main] DEBUG loci.formats.FormatHandler - t00000/s00/4/cells/
2023-01-17 13:16:23,574 [main] DEBUG loci.formats.FormatHandler - t00000/s00/5/cells/
2023-01-17 13:16:23,574 [main] DEBUG loci.formats.FormatHandler - t00000/s00/6/cells/
2023-01-17 13:16:23,575 [main] DEBUG loci.formats.FormatHandler - t00000/s00/7/cells/
2023-01-17 13:34:01,840 [main] DEBUG loci.common.Location - Location.mapFile: embedded-stream.raw -> null
2023-01-17 13:34:01,842 [main] DEBUG loci.common.Location - Location.mapFile: embedded-stream.raw -> null
2023-01-17 13:34:02,047 [main] DEBUG loci.formats.Memoizer - loaded memo file: /data/idr0048/.WB.xml.bfmemo (8316 bytes)
2023-01-17 13:34:02,048 [main] DEBUG loci.formats.Memoizer - start[1673962441924] time[123] tag[loci.formats.Memoizer.loadMemo]
2023-01-17 13:34:02,048 [main] DEBUG loci.formats.Memoizer - start[1673962441897] time[151] tag[loci.formats.Memoizer.setId]
2023-01-17 13:34:02,057 [main] DEBUG loci.formats.Memoizer - loaded memo file: /data/idr0048/.WB.xml.bfmemo (8316 bytes)
2023-01-17 13:34:02,057 [main] DEBUG loci.formats.Memoizer - start[1673962442050] time[7] tag[loci.formats.Memoizer.loadMemo]
2023-01-17 13:34:02,058 [main] DEBUG loci.formats.Memoizer - start[1673962442049] time[8] tag[loci.formats.Memoizer.setId]
2023-01-17 13:34:02,067 [main] DEBUG loci.formats.Memoizer - loaded memo file: /data/idr0048/.WB.xml.bfmemo (8316 bytes)
2023-01-17 13:34:02,067 [main] DEBUG loci.formats.Memoizer - start[1673962442058] time[8] tag[loci.formats.Memoizer.loadMemo]
2023-01-17 13:34:02,068 [main] DEBUG loci.formats.Memoizer - start[1673962442058] time[9] tag[loci.formats.Memoizer.setId]
2023-01-17 13:34:02,075 [main] DEBUG loci.formats.Memoizer - loaded memo file: /data/idr0048/.WB.xml.bfmemo (8316 bytes)
2023-01-17 13:34:02,075 [main] DEBUG loci.formats.Memoizer - start[1673962442068] time[7] tag[loci.formats.Memoizer.loadMemo]
2023-01-17 13:34:02,076 [main] DEBUG loci.formats.Memoizer - start[1673962442068] time[7] tag[loci.formats.Memoizer.setId]
2023-01-17 13:34:02,510 [main] INFO  c.g.bioformats2raw.Converter - Using 8 pyramid resolutions
2023-01-17 13:34:02,510 [main] INFO  c.g.bioformats2raw.Converter - Preparing to write pyramid sizeX 19120 (tileWidth: 1024) sizeY 13350 (tileWidth: 1024) sizeZ 91 (tileDepth: 1) imageCount 273
2023-01-17 13:34:02,510 [main] DEBUG c.g.bioformats2raw.Converter - setSeriesLevelMetadata(0, 8)
2023-01-17 13:34:02,511 [main] DEBUG c.g.bioformats2raw.Converter -   seriesString = 0
2023-01-17 13:34:02,511 [main] DEBUG c.g.bioformats2raw.Converter -   resolutionString = 0/0
2023-01-17 13:34:02,511 [main] DEBUG c.g.bioformats2raw.Converter -   creating subgroup 9846152_logging.zarr/0
2023-01-17 13:34:02,532 [main] DEBUG c.g.bioformats2raw.Converter -     finished writing subgroup attributes
2023-01-17 13:34:02,620 [pool-1-thread-2] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 1, 0, 0, 0] to 0/0
2023-01-17 13:34:02,620 [pool-1-thread-3] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 2, 0, 0, 0] to 0/0
2023-01-17 13:34:02,620 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 0, 0, 0, 0] to 0/0
2023-01-17 13:34:02,620 [pool-1-thread-4] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 0, 1, 0, 0] to 0/0
2023-01-17 13:34:03,364 [pool-1-thread-4] INFO  c.g.bioformats2raw.Converter - chunk read complete 1/72618
2023-01-17 13:34:03,364 [pool-1-thread-4] INFO  org.perf4j.TimingLogger - start[1673962442621] time[743] tag[getChunk]
2023-01-17 13:34:03,619 [pool-1-thread-3] INFO  c.g.bioformats2raw.Converter - chunk read complete 2/72618
2023-01-17 13:34:03,619 [pool-1-thread-3] INFO  org.perf4j.TimingLogger - start[1673962442621] time[998] tag[getChunk]
2023-01-17 13:34:03,625 [pool-1-thread-4] DEBUG c.g.bioformats2raw.Converter - start[1673962443367] time[257] tag[writeBytes]
2023-01-17 13:34:03,625 [pool-1-thread-4] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=1 xx=0 yy=0 zz=1 width=1024 height=1024 depth=1
2023-01-17 13:34:03,627 [pool-1-thread-4] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 1, 1, 0, 0] to 0/0
2023-01-17 13:34:03,643 [pool-1-thread-3] DEBUG c.g.bioformats2raw.Converter - start[1673962443620] time[22] tag[writeBytes]
2023-01-17 13:34:03,643 [pool-1-thread-3] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=182 xx=0 yy=0 zz=0 width=1024 height=1024 depth=1
2023-01-17 13:34:03,644 [pool-1-thread-3] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 2, 1, 0, 0] to 0/0
2023-01-17 13:34:03,964 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - chunk read complete 3/72618
2023-01-17 13:34:03,964 [pool-1-thread-1] INFO  org.perf4j.TimingLogger - start[1673962442621] time[1343] tag[getChunk]
2023-01-17 13:34:03,971 [pool-1-thread-2] INFO  c.g.bioformats2raw.Converter - chunk read complete 4/72618
2023-01-17 13:34:03,971 [pool-1-thread-2] INFO  org.perf4j.TimingLogger - start[1673962442620] time[1350] tag[getChunk]
2023-01-17 13:34:03,981 [pool-1-thread-1] DEBUG c.g.bioformats2raw.Converter - start[1673962443965] time[16] tag[writeBytes]
2023-01-17 13:34:03,981 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=0 xx=0 yy=0 zz=0 width=1024 height=1024 depth=1
2023-01-17 13:34:03,983 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 0, 2, 0, 0] to 0/0
2023-01-17 13:34:03,994 [pool-1-thread-2] DEBUG c.g.bioformats2raw.Converter - start[1673962443972] time[21] tag[writeBytes]
2023-01-17 13:34:03,994 [pool-1-thread-2] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=91 xx=0 yy=0 zz=0 width=1024 height=1024 depth=1
2023-01-17 13:34:03,995 [pool-1-thread-2] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 1, 2, 0, 0] to 0/0
2023-01-17 13:34:04,265 [pool-1-thread-3] INFO  c.g.bioformats2raw.Converter - chunk read complete 5/72618

...

2023-01-17 15:20:53,620 [pool-1-thread-2] INFO  org.perf4j.TimingLogger - start[1673968850253] time[3366] tag[getChunk]
2023-01-17 15:20:53,641 [pool-1-thread-2] DEBUG c.g.bioformats2raw.Converter - start[1673968853620] time[20] tag[writeBytes]
2023-01-17 15:20:53,641 [pool-1-thread-2] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=147 xx=9216 yy=3072 zz=56 width=1024 height=1024 depth=1
2023-01-17 15:20:53,641 [pool-1-thread-2] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 0, 58, 3072, 9216] to 0/0
2023-01-17 15:20:54,994 [pool-1-thread-4] INFO  c.g.bioformats2raw.Converter - chunk read complete 18190/72618
2023-01-17 15:20:54,994 [pool-1-thread-4] INFO  org.perf4j.TimingLogger - start[1673968850798] time[4196] tag[getChunk]
2023-01-17 15:20:55,017 [pool-1-thread-4] DEBUG c.g.bioformats2raw.Converter - start[1673968854995] time[21] tag[writeBytes]
2023-01-17 15:20:55,017 [pool-1-thread-4] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=238 xx=9216 yy=3072 zz=56 width=1024 height=1024 depth=1
2023-01-17 15:20:55,017 [pool-1-thread-4] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 1, 58, 3072, 9216] to 0/0
2023-01-17 15:20:55,899 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - chunk read complete 18191/72618
2023-01-17 15:20:55,899 [pool-1-thread-1] INFO  org.perf4j.TimingLogger - start[1673968852741] time[3157] tag[getChunk]
2023-01-17 15:20:55,935 [pool-1-thread-1] DEBUG c.g.bioformats2raw.Converter - start[1673968855900] time[35] tag[writeBytes]
2023-01-17 15:20:55,935 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=239 xx=9216 yy=3072 zz=57 width=1024 height=1024 depth=1
2023-01-17 15:20:55,935 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 2, 58, 3072, 9216] to 0/0
2023-01-17 15:23:44,928 [pool-1-thread-2] INFO  c.g.bioformats2raw.Converter - chunk read complete 18192/72618
2023-01-17 15:23:44,981 [pool-1-thread-2] INFO  org.perf4j.TimingLogger - start[1673968853641] time[171339] tag[getChunk]

Using --max_workers=1 doesn't seem to make a difference:

$ bioformats2raw WB.xml 9846152_mw1.zarr --max_workers=1 --debug > bf2raw_mw1.log
OpenJDK 64-Bit Server VM warning: You have loaded library /tmp/opencv_openpnp1435327528824061833/nu/pattern/opencv/linux/x86_64/libopencv_java342.so which might have disabled stack guard. The VM will try to fix the stack guard now.
It's highly recommended that you fix the library with 'execstack -c <libfile>', or link it with '-z noexecstack'.
Killed

$ find 9846152_mw1.zarr/ -type f | wc -l
18211
bf2raw_mw1.log
2023-01-18 11:06:04,036 [main] DEBUG loci.formats.ClassList - Could not find loci.formats.in.URLReader
java.lang.ClassNotFoundException: loci.formats.in.URLReader
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)
        at loci.formats.ClassList.parseLine(ClassList.java:196)
        at loci.formats.ClassList.parseFile(ClassList.java:258)
        at loci.formats.ClassList.<init>(ClassList.java:138)
        at loci.formats.ClassList.<init>(ClassList.java:122)
        at loci.formats.ImageReader.getDefaultReaderClasses(ImageReader.java:80)
        at com.glencoesoftware.bioformats2raw.Converter.getBaseReaderClass(Converter.java:2105)
        at com.glencoesoftware.bioformats2raw.Converter.convert(Converter.java:538)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:514)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:109)
        at picocli.CommandLine.executeUserObject(CommandLine.java:1953)
        at picocli.CommandLine.access$1300(CommandLine.java:145)
        at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2352)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2346)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2311)
        at picocli.CommandLine$AbstractParseResultHandler.handleParseResult(CommandLine.java:2172)
        at picocli.CommandLine.parseWithHandlers(CommandLine.java:2550)
        at picocli.CommandLine.parseWithHandler(CommandLine.java:2485)
        at picocli.CommandLine.call(CommandLine.java:2761)
        at com.glencoesoftware.bioformats2raw.Converter.main(Converter.java:2274)
2023-01-18 11:06:04,056 [main] DEBUG loci.formats.ClassList - Could not find loci.formats.in.SlideBook6Reader
java.lang.ClassNotFoundException: loci.formats.in.SlideBook6Reader
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)
        at loci.formats.ClassList.parseLine(ClassList.java:196)
        at loci.formats.ClassList.parseFile(ClassList.java:258)
        at loci.formats.ClassList.<init>(ClassList.java:138)
        at loci.formats.ClassList.<init>(ClassList.java:122)
        at loci.formats.ImageReader.getDefaultReaderClasses(ImageReader.java:80)
        at com.glencoesoftware.bioformats2raw.Converter.getBaseReaderClass(Converter.java:2105)
        at com.glencoesoftware.bioformats2raw.Converter.convert(Converter.java:538)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:514)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:109)
        at picocli.CommandLine.executeUserObject(CommandLine.java:1953)
        at picocli.CommandLine.access$1300(CommandLine.java:145)
        at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2352)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2346)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2311)
        at picocli.CommandLine$AbstractParseResultHandler.handleParseResult(CommandLine.java:2172)
        at picocli.CommandLine.parseWithHandlers(CommandLine.java:2550)
        at picocli.CommandLine.parseWithHandler(CommandLine.java:2485)
        at picocli.CommandLine.call(CommandLine.java:2761)
        at com.glencoesoftware.bioformats2raw.Converter.main(Converter.java:2274)
2023-01-18 11:06:04,058 [main] DEBUG loci.formats.ClassList - Could not find loci.formats.in.ScreenReader
java.lang.ClassNotFoundException: loci.formats.in.ScreenReader
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)
        at loci.formats.ClassList.parseLine(ClassList.java:196)
        at loci.formats.ClassList.parseFile(ClassList.java:258)
        at loci.formats.ClassList.<init>(ClassList.java:138)
        at loci.formats.ClassList.<init>(ClassList.java:122)
        at loci.formats.ImageReader.getDefaultReaderClasses(ImageReader.java:80)
        at com.glencoesoftware.bioformats2raw.Converter.getBaseReaderClass(Converter.java:2105)
        at com.glencoesoftware.bioformats2raw.Converter.convert(Converter.java:538)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:514)
        at com.glencoesoftware.bioformats2raw.Converter.call(Converter.java:109)
        at picocli.CommandLine.executeUserObject(CommandLine.java:1953)
        at picocli.CommandLine.access$1300(CommandLine.java:145)
        at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2352)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2346)
        at picocli.CommandLine$RunLast.handle(CommandLine.java:2311)
        at picocli.CommandLine$AbstractParseResultHandler.handleParseResult(CommandLine.java:2172)
        at picocli.CommandLine.parseWithHandlers(CommandLine.java:2550)
        at picocli.CommandLine.parseWithHandler(CommandLine.java:2485)
        at picocli.CommandLine.call(CommandLine.java:2761)
        at com.glencoesoftware.bioformats2raw.Converter.main(Converter.java:2274)
2023-01-18 11:06:04,058 [main] DEBUG loci.formats.ClassList - Could not find loci.formats.in.ZarrReader

... 

2023-01-18 12:56:47,519 [pool-1-thread-1] INFO  org.perf4j.TimingLogger - start[1674046606753] time[766] tag[getChunk]
2023-01-18 12:56:47,640 [pool-1-thread-1] DEBUG c.g.bioformats2raw.Converter - start[1674046607520] time[120] tag[writeBytes]
2023-01-18 12:56:47,641 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=242 xx=9216 yy=3072 zz=60 width=1024 height=1024 depth=1
2023-01-18 12:56:47,688 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 0, 61, 3072, 9216] to 0/0
2023-01-18 12:56:48,840 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - chunk read complete 18202/72618
2023-01-18 12:56:48,840 [pool-1-thread-1] INFO  org.perf4j.TimingLogger - start[1674046607688] time[1151] tag[getChunk]
2023-01-18 12:56:48,967 [pool-1-thread-1] DEBUG c.g.bioformats2raw.Converter - start[1674046608840] time[126] tag[writeBytes]
2023-01-18 12:56:48,967 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=61 xx=9216 yy=3072 zz=61 width=1024 height=1024 depth=1
2023-01-18 12:56:49,022 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 1, 61, 3072, 9216] to 0/0
2023-01-18 12:56:50,360 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - chunk read complete 18203/72618
2023-01-18 12:56:50,360 [pool-1-thread-1] INFO  org.perf4j.TimingLogger - start[1674046609022] time[1337] tag[getChunk]
2023-01-18 12:56:50,424 [pool-1-thread-1] DEBUG c.g.bioformats2raw.Converter - start[1674046610361] time[63] tag[writeBytes]
2023-01-18 12:56:50,424 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - Successfully processed chunk; resolution=0 plane=152 xx=9216 yy=3072 zz=61 width=1024 height=1024 depth=1
2023-01-18 12:56:50,458 [pool-1-thread-1] INFO  c.g.bioformats2raw.Converter - requesting tile to write at [0, 2, 61, 3072, 9216] to 0/0

Seb: "from var/log/messages"

(base) [sbesson@pilot-zarr1-dev ~]$ sudo grep Out /var/log/messages
Jan 17 15:24:41 pilot-zarr1-dev kernel: Out of memory: Kill process 28742 (java) score 976 or sacrifice child
Jan 18 12:57:11 pilot-zarr1-dev kernel: Out of memory: Kill process 29765 (java) score 975 or sacrifice child

Dom: see https://docs.openmicroscopy.org/bio-formats/5.9.1/users/comlinetools/index.html#command-line-environment
Trying...

(base) [wmoore@pilot-zarr1-dev idr0048]$ export BF_MAX_MEM=10g
(base) [wmoore@pilot-zarr1-dev idr0048]$ bioformats2raw WB.xml 9846152_mem10g.zarr --debug > bf2raw_mem10g.log
```

I wouldn't expect setting BF_MAX_MEM to do anything here. That is specific to Bio-Formats command line tools like bfconvert and showinf; bioformats2raw does not recognize it. To change the heap size for bioformats2raw, use something like:

$ JAVA_OPTS="-Xmx10g" bioformats2raw ...

I was able to reproduce this problem after a while with 0.6.0, default memory settings, and 1 worker. For anyone else following along, note this is public data: https://downloads.openmicroscopy.org/images/BDV/idr0048/

I don't see anything obvious to suggest that this is fundamentally a bioformats2raw issue; the image dimensions are well within what we've successfully converted from other original data formats. I suspect that fixing this will require some updates to the BDV reader to reduce memory consumption during tile reading.

I don't see anything obvious to suggest that this is fundamentally a bioformats2raw issue;

Did you mean a bioformats issue as per your comment about the BDV reader?

Thanks @melissalinkert - trying JAVA_OPTS="-Xmx10g" bioformats2raw WB.xml 9846152_mem10g.zarr --debug > bf2raw_mem10g.log ...

I don't see anything obvious to suggest that this is fundamentally a bioformats2raw issue;

Did you mean a bioformats issue as per your comment about the BDV reader?

Sorry, what I meant is I think BDV reader is the place to investigate first. That means there may not be anything we can do here in the bioformats2raw repo until any BDV fixes are released and the Bio-Formats version number is ready to be bumped.

Hmmm - looks like that memory boost had no effect:

(base) [wmoore@pilot-zarr1-dev idr0048]$ JAVA_OPTS="-Xmx10g" bioformats2raw WB.xml 9846152_mem10g.zarr --debug > bf2raw_mem10g.log
OpenJDK 64-Bit Server VM warning: You have loaded library /tmp/opencv_openpnp600874666168285863/nu/pattern/opencv/linux/x86_64/libopencv_java342.so which might have disabled stack guard. The VM will try to fix the stack guard now.
It's highly recommended that you fix the library with 'execstack -c <libfile>', or link it with '-z noexecstack'.
Killed
(base) [wmoore@pilot-zarr1-dev idr0048]$ ls 9846152_mem10g.zarr/0/
0
(base) [wmoore@pilot-zarr1-dev idr0048]$ find 9846152_mem10g.zarr/ -type f | wc -l
18203

Closing here, since memory usage issues will need to be addressed in BDV reader (and I can't transfer the issue across organizations).

jburel commented

@will-moore could you open an issue on ome/bioformats describing the problem? so it is captured