SAR workflow performance

I’m trying to process a couple of Sentinel-1 products with the GPT graph found at the end. The two input products are S1A_IW_SLC__1SDV_20180105T052632_20180105T052659_020015_02218B_9675.SAFE and S1B_IW_SLC__1SDV_20180111T052601_20180111T052628_009119_01050B_416F.SAFE.

My specifications are:

  • CPU: 2 x Intel® Xeon® CPU E5-2650 v3 @ 2.30GHz (40 hardware threads)
  • RAM: 128 GB
  • HDD
  • Linux x64
  • SNAP 6.0

The processing seems to be going very slowly. It’s been running for a couple of hours, and the process is at 79h 35m CPU time. See the following screenshot:

A couple of things to note:

  • The memory usage is rather high: 48 GB resident (it got to 49.5 GB while I was writing this post). The two input products are 15 GB in size (together)
  • The system CPU time is very high (around 12% of the total)
  • The processing seems to have stopped, more or less (it’s no longer writing to disk)
  • The output has been ....10%....20%....30%...INFO: org.hsqldb.persist.Logger: Database closed – for a couple of hours
  • The application is running 95 threads (NLWP column in the screenshot)
  • Some 1.8 GB worth of data got written to the output location: 878M May 21 13:46 Intensity_VV_mst_05Jan2018.img and 878M May 21 13:46 Intensity_VV_slv1_11Jan2018.img. It’s 17:20 now, for the record.
  • There’s 414 MB worth of data in /tmp/imageioxxxx.tmp TIFF files. The last one was modified at 12:11.
  • perf seems to indicate that a lot of time is spent in memory allocation, and thread synchronization at times:

  • Sample perf stat output:
 Performance counter stats for process id '2513':

    1425289.493145      task-clock (msec)         #   18.769 CPUs utilized          
             8,005      context-switches          #    0.006 K/sec                  
             2,359      cpu-migrations            #    0.002 K/sec                  
        14,023,273      page-faults               #    0.010 M/sec                  
 3,701,611,799,519      cycles                    #    2.597 GHz                    
   808,689,330,867      instructions              #    0.22  insn per cycle         
   163,275,960,525      branches                  #  114.556 M/sec                  
       269,993,170      branch-misses             #    0.17% of all branches        

      75.939357535 seconds time elapsed
 Performance counter stats for process id '2513':

                 3      syscalls:sys_enter_utimes
                 3      syscalls:sys_exit_utimes
                18      syscalls:sys_enter_newstat
                18      syscalls:sys_exit_newstat
                10      syscalls:sys_enter_newlstat
                10      syscalls:sys_exit_newlstat
                 3      syscalls:sys_enter_open
                 3      syscalls:sys_exit_open
                 3      syscalls:sys_enter_close
                 3      syscalls:sys_exit_close
                16      syscalls:sys_enter_mprotect
                16      syscalls:sys_exit_mprotect
            10,096      syscalls:sys_enter_futex
            10,094      syscalls:sys_exit_futex
            24,344      syscalls:sys_enter_sched_yield
            24,344      syscalls:sys_exit_sched_yield
                 6      syscalls:sys_enter_mmap
                 6      syscalls:sys_exit_mmap

      90.527997141 seconds time elapsed

In addition, we tried the same workload on two different machines:

  • on one, the processing is at around 62% with 740h CPU time and 91.5 GB RAM used
  • on another, the processing seems to have stopped completely (no CPU used, no writes to disk) at 30% with 34.5 GB RAM used

The two instances have been running since last Thursday (four days ago).

I’m not familiar with the Java debugging and profiling tools.

My tentative conclusions are that:

  • SNAP tends to do a lot of extra copying of the raster data
  • There is a lot of thread synchronization (and threading in general) going on; this is not apparent in the informantion I pasted above, but seemed to happen in the first 20 minutes or so of processing
  • Even so, the thread synchronization isn’t necessarily obvious in the system call list, because Java uses spinlocks (which can get acquired without a system call
  • The stuck instance (on the other server) might be in a deadlock waiting for disk, so that’s okay

Is the processing speed and behaviour I’m seeing in line with the one that’s expected?

Command line: /opt/snap/bin/gpt s1-amplitude.xml \ S1A_IW_SLC__1SDV_20180105T052632_20180105T052659_020015_02218B_9675.SAFE/manifest.safe \ S1B_IW_SLC__1SDV_20180111T052601_20180111T052628_009119_01050B_416F.SAFE/manifest.safe

GPT graph:

<graph id="Graph">
  <version>1.0</version>
  <!-- STEP 0 -->
  <!-- First product -->
  <node id="Apply-Orbit-File(1)">
    <operator>Apply-Orbit-File</operator>
    <sources>
      <sourceProduct refid="${sourceProduct1}"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <orbitType>Sentinel Precise (Auto Download)</orbitType>
      <polyDegree>3</polyDegree>
      <continueOnFail>true</continueOnFail>
    </parameters>
  </node>
  <node id="Calibration(1)">
    <operator>Calibration</operator>
    <sources>
      <sourceProduct refid="Apply-Orbit-File(1)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <sourceBands/>
      <auxFile>Latest Auxiliary File</auxFile>
      <externalAuxFile/>
      <outputImageInComplex>true</outputImageInComplex>
      <outputImageScaleInDb>false</outputImageScaleInDb>
      <createGammaBand>false</createGammaBand>
      <createBetaBand>false</createBetaBand>
      <selectedPolarisations/>
      <outputSigmaBand>true</outputSigmaBand>
      <outputGammaBand>false</outputGammaBand>
      <outputBetaBand>false</outputBetaBand>
    </parameters>
  </node>
  <node id="TOPSAR-Split(1-1)">
    <operator>TOPSAR-Split</operator>
    <sources>
      <sourceProduct refid="Calibration(1)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <subswath>IW1</subswath>
      <selectedPolarisations>VV</selectedPolarisations>
      <firstBurstIndex>1</firstBurstIndex>
      <lastBurstIndex>9</lastBurstIndex>
      <wktAoi/>
    </parameters>
  </node>
  <node id="TOPSAR-Split(1-2)">
    <operator>TOPSAR-Split</operator>
    <sources>
      <sourceProduct refid="Calibration(1)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <subswath>IW2</subswath>
      <selectedPolarisations>VV</selectedPolarisations>
      <firstBurstIndex>1</firstBurstIndex>
      <lastBurstIndex>9</lastBurstIndex>
      <wktAoi/>
    </parameters>
  </node>
  <node id="TOPSAR-Split(1-3)">
    <operator>TOPSAR-Split</operator>
    <sources>
      <sourceProduct refid="Calibration(1)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <subswath>IW3</subswath>
      <selectedPolarisations>VV</selectedPolarisations>
      <firstBurstIndex>1</firstBurstIndex>
      <lastBurstIndex>9</lastBurstIndex>
      <wktAoi/>
    </parameters>
  </node>
  
  <!-- Second Product -->
  <node id="Apply-Orbit-File(2)">
    <operator>Apply-Orbit-File</operator>
    <sources>
      <sourceProduct refid="${sourceProduct2}"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <orbitType>Sentinel Precise (Auto Download)</orbitType>
      <polyDegree>3</polyDegree>
      <continueOnFail>true</continueOnFail>
    </parameters>
  </node>
  <node id="Calibration(2)">
    <operator>Calibration</operator>
    <sources>
      <sourceProduct refid="Apply-Orbit-File(2)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <sourceBands/>
      <auxFile>Latest Auxiliary File</auxFile>
      <externalAuxFile/>
      <outputImageInComplex>true</outputImageInComplex>
      <outputImageScaleInDb>false</outputImageScaleInDb>
      <createGammaBand>false</createGammaBand>
      <createBetaBand>false</createBetaBand>
      <selectedPolarisations/>
      <outputSigmaBand>true</outputSigmaBand>
      <outputGammaBand>false</outputGammaBand>
      <outputBetaBand>false</outputBetaBand>
    </parameters>
  </node>
  <node id="TOPSAR-Split(2-1)">
    <operator>TOPSAR-Split</operator>
    <sources>
      <sourceProduct refid="Calibration(2)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <subswath>IW1</subswath>
      <selectedPolarisations>VV</selectedPolarisations>
      <firstBurstIndex>1</firstBurstIndex>
      <lastBurstIndex>9</lastBurstIndex>
      <wktAoi/>
    </parameters>
  </node>
  <node id="TOPSAR-Split(2-2)">
    <operator>TOPSAR-Split</operator>
    <sources>
      <sourceProduct refid="Calibration(2)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <subswath>IW2</subswath>
      <selectedPolarisations>VV</selectedPolarisations>
      <firstBurstIndex>1</firstBurstIndex>
      <lastBurstIndex>9</lastBurstIndex>
      <wktAoi/>
    </parameters>
  </node>
  <node id="TOPSAR-Split(2-3)">
    <operator>TOPSAR-Split</operator>
    <sources>
      <sourceProduct refid="Calibration(2)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <subswath>IW3</subswath>
      <selectedPolarisations>VV</selectedPolarisations>
      <firstBurstIndex>1</firstBurstIndex>
      <lastBurstIndex>9</lastBurstIndex>
      <wktAoi/>
    </parameters>
  </node>
  
  <!-- STEP 1 -->
  <node id="Back-Geocoding(1)">
    <operator>Back-Geocoding</operator>
    <sources>
      <sourceProduct.1 refid="TOPSAR-Split(1-1)"/>
      <sourceProduct.2 refid="TOPSAR-Split(2-1)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <demName>SRTM 3Sec</demName>
      <demResamplingMethod>BICUBIC_INTERPOLATION</demResamplingMethod>
      <externalDEMFile/>
      <externalDEMNoDataValue>0.0</externalDEMNoDataValue>
      <resamplingType>BISINC_5_POINT_INTERPOLATION</resamplingType>
      <maskOutAreaWithoutElevation>true</maskOutAreaWithoutElevation>
      <outputRangeAzimuthOffset>false</outputRangeAzimuthOffset>
      <outputDerampDemodPhase>false</outputDerampDemodPhase>
      <disableReramp>false</disableReramp>
    </parameters>
  </node>
  <node id="TOPSAR-Deburst(1)">
    <operator>TOPSAR-Deburst</operator>
    <sources>
      <sourceProduct refid="Back-Geocoding(1)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <selectedPolarisations>VV</selectedPolarisations>
    </parameters>
  </node>
  <node id="Back-Geocoding(2)">
    <operator>Back-Geocoding</operator>
    <sources>
      <sourceProduct.1 refid="TOPSAR-Split(1-2)"/>
      <sourceProduct.2 refid="TOPSAR-Split(2-2)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <demName>SRTM 3Sec</demName>
      <demResamplingMethod>BICUBIC_INTERPOLATION</demResamplingMethod>
      <externalDEMFile/>
      <externalDEMNoDataValue>0.0</externalDEMNoDataValue>
      <resamplingType>BISINC_5_POINT_INTERPOLATION</resamplingType>
      <maskOutAreaWithoutElevation>true</maskOutAreaWithoutElevation>
      <outputRangeAzimuthOffset>false</outputRangeAzimuthOffset>
      <outputDerampDemodPhase>false</outputDerampDemodPhase>
      <disableReramp>false</disableReramp>
    </parameters>
  </node>
  <node id="TOPSAR-Deburst(2)">
    <operator>TOPSAR-Deburst</operator>
    <sources>
      <sourceProduct refid="Back-Geocoding(2)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <selectedPolarisations>VV</selectedPolarisations>
    </parameters>
  </node>
  <node id="Back-Geocoding(3)">
    <operator>Back-Geocoding</operator>
    <sources>
      <sourceProduct.1 refid="TOPSAR-Split(1-3)"/>
      <sourceProduct.2 refid="TOPSAR-Split(2-3)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <demName>SRTM 3Sec</demName>
      <demResamplingMethod>BICUBIC_INTERPOLATION</demResamplingMethod>
      <externalDEMFile/>
      <externalDEMNoDataValue>0.0</externalDEMNoDataValue>
      <resamplingType>BISINC_5_POINT_INTERPOLATION</resamplingType>
      <maskOutAreaWithoutElevation>true</maskOutAreaWithoutElevation>
      <outputRangeAzimuthOffset>false</outputRangeAzimuthOffset>
      <outputDerampDemodPhase>false</outputDerampDemodPhase>
      <disableReramp>false</disableReramp>
    </parameters>
  </node>
  <node id="TOPSAR-Deburst(3)">
    <operator>TOPSAR-Deburst</operator>
    <sources>
      <sourceProduct refid="Back-Geocoding(3)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <selectedPolarisations>VV</selectedPolarisations>
    </parameters>
  </node>
 
  <!-- STEP 2 -->
  <node id="TOPSAR-Merge">
    <operator>TOPSAR-Merge</operator>
    <sources>
      <sourceProduct.1 refid="TOPSAR-Deburst(1)"/>
	  <sourceProduct.2 refid="TOPSAR-Deburst(2)"/>
	  <sourceProduct.3 refid="TOPSAR-Deburst(3)"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <selectedPolarisations>VV</selectedPolarisations>
    </parameters>
  </node>

  <!-- STEP 3 -->
  <node id="Terrain-Correction">
    <operator>Terrain-Correction</operator>
    <sources>
      <sourceProduct refid="TOPSAR-Merge"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <sourceBands/>
      <demName>SRTM 3Sec</demName>
      <externalDEMFile/>
      <externalDEMNoDataValue>0.0</externalDEMNoDataValue>
      <externalDEMApplyEGM>true</externalDEMApplyEGM>
      <demResamplingMethod>BILINEAR_INTERPOLATION</demResamplingMethod>
      <imgResamplingMethod>BILINEAR_INTERPOLATION</imgResamplingMethod>
      <pixelSpacingInMeter>20.0</pixelSpacingInMeter>
      <pixelSpacingInDegree>1.796630568239043E-4</pixelSpacingInDegree>
      <mapProjection>GEOGCS[&quot;WGS84(DD)&quot;, 
  DATUM[&quot;WGS84&quot;, 
    SPHEROID[&quot;WGS84&quot;, 6378137.0, 298.257223563]], 
  PRIMEM[&quot;Greenwich&quot;, 0.0], 
  UNIT[&quot;degree&quot;, 0.017453292519943295], 
  AXIS[&quot;Geodetic longitude&quot;, EAST], 
  AXIS[&quot;Geodetic latitude&quot;, NORTH]]</mapProjection>
      <alignToStandardGrid>false</alignToStandardGrid>
      <standardGridOriginX>0.0</standardGridOriginX>
      <standardGridOriginY>0.0</standardGridOriginY>
      <nodataValueAtSea>true</nodataValueAtSea>
      <saveDEM>false</saveDEM>
      <saveLatLon>false</saveLatLon>
      <saveIncidenceAngleFromEllipsoid>false</saveIncidenceAngleFromEllipsoid>
      <saveLocalIncidenceAngle>false</saveLocalIncidenceAngle>
      <saveProjectedLocalIncidenceAngle>false</saveProjectedLocalIncidenceAngle>
      <saveSelectedSourceBand>true</saveSelectedSourceBand>
      <outputComplex>false</outputComplex>
      <applyRadiometricNormalization>false</applyRadiometricNormalization>
      <saveSigmaNought>false</saveSigmaNought>
      <saveGammaNought>false</saveGammaNought>
      <saveBetaNought>false</saveBetaNought>
      <incidenceAngleForSigma0>Use projected local incidence angle from DEM</incidenceAngleForSigma0>
      <incidenceAngleForGamma0>Use projected local incidence angle from DEM</incidenceAngleForGamma0>
      <auxFile>Latest Auxiliary File</auxFile>
      <externalAuxFile/>
    </parameters>
  </node>
  <node id="Write">
    <operator>Write</operator>
    <sources>
      <sourceProduct refid="Terrain-Correction"/>
    </sources>
    <parameters class="com.bc.ceres.binding.dom.XppDomElement">
      <file>target_TerrCorr</file>
      <formatName>BEAM-DIMAP</formatName>
    </parameters>
  </node>
</graph>

UPDATE: I stopped it at 44% with 1282h CPU time and 83 GB RAM. This approach is clearly not working.

Did you happen to find out what the problem is/was?

The installer defaulted to a Java heap size of 100 GB or so. I reduced it to a more reasonable value (-Xmx8G) in gpt.vmoptions and the performance improved a lot.

2 Likes