Generating texture or exporting OBJ causes PhotoScan to segfault?

[jbak9141]

Hi all,

I've been testing a small python export script to generate and export a model in various formats and have run into a few issues with the OBJ/texture.


Platform details, steps run and a few observations prior to the crash are as follows:

Platform details:

Agisoft PhotoScan Professional Version: 1.3.4 build 5067 (64 bit)
Platform: Linux
OpenGL Vendor: VMware, Inc.
OpenGL Renderer: Gallium 0.4 on llvmpipe (LLVM 4.0, 256 bits)
OpenGL Version: 3.0 Mesa 17.0.7
Maximum Texture Size: 8192
Quad Buffered Stereo: not enabled
ARB_vertex_buffer_object: supported
ARB_texture_non_power_of_two: supported

Steps run:

• buildDenseCloud - medium / aggressive / keep + reuse depth
• chunk.dense_cloud.assignClass(2)
• buildDem - DenseCloudData, EnabledInterpolation
• exportDem - RasterFormatTiles+ImageFormatTIFF, tiff_big=True
• buildOrthomosaic - ElevationData, MosaicBlending, color_correction=False
• exportOrtho - RasterTransformNone, RasterFormatTiles+ImageFormatTIFF, tiff_big=True
• buildModel - HighFaceCount, HeightField, EnabledInterpolation, ElevationData, classes=[2]
• buildTexture - size=2048
• exportModel - ModelFormatOBJ, texture=True, normals=False, colors=False, cameras=False

Observations:

 — Building the texture took much longer than expected. For a 402 image run, it took several hours. Nothing else intensive is running on the machine at all.
 — Exporting the model took MUCH longer than expected: projected times varied, but were in the hundreds of hours. I'm calling the export method with a callback and get the progress updates, which indicate that progress is about 0.25 percentage-units per MINUTE.
 — Except for these things, there is nothing really suspicious in the logs before the crash.
 — Some exports crash when they are a tiny tiny bit through (1% or 2%) and some get much longer (45%) before crashing. Some, the smallest ones, make it all the way through.
 — Not surprisingly, the texture takes longer to build with more photos/megapixels. However, while it takes seconds to minutes for tens of photos it seems to take many hours for hundreds of cameras, which is significantly longer than expected.   — Similarly the "exportModel" call seems to exhibit an even higher order of non-linearity.

For the two most recent tests using the same series of steps above I found the following:

 — A small run with 82 photos got to about 42% before crashing.
 — A larger run with 402 photos got to 0.55% before crashing.

Is there any known issue with the OBJ export, or a way to debug this further?


Cheers,

J

[Phogi]

Hi Jbak9141,

Can confirm that there appears to be a regression between 1.3.2 and 1.3.4. For a small project with about 20 low-resolution photos, the same "exportModel" operation took 1.9 seconds on 1.3.2 and about 18.5 seconds on 1.3.4 (average of three runs). The input data and processing steps are identical (all steps, including loading the project, were scripted).

Hello Alexey, does this a known issue?

Thanks,

[Alexey Pasumansky]

Hello jbak9141,

Can you please provide the processing log related to the mesh generation end export operations?

Also have you already submitted the crash report? It would be helpful, if you could send a crash report with some comment, so that we could identify it.

And please provide some additional information regarding the following steps:

- chunk.dense_cloud.assignClass(2)
- buildModel - HighFaceCount, HeightField, EnabledInterpolation, ElevationData, classes=[2]
- buildTexture - size=2048

How you are performing dense cloud class assignment?
Build Model function is using PointCloudData or DenseCloudData on input, it cannot be based on ElevationData.
Texture Generation via Python requires BuildUV and BuildTexture steps to be executed.

[jbak9141]

Hi Alexey,

Can you please provide the processing log related to the mesh generation end export operations?

And please provide some additional information regarding the following steps:

- chunk.dense_cloud.assignClass[2]
- buildModel - HighFaceCount, HeightField, EnabledInterpolation, ElevationData, classes=[2]
- buildTexture - size=2048

The steps we followed are:

Assign all points to class 2 (Ground) in point cloud)

Buildmodel (we had originally used the elevation data source for this call but since tested with the dense cloud with the same results)

Build UV map and Build Texture

Here are the function calls for each step respectively:

chunk.dense_cloud.assignClass(2)

chunk.buildModel(
            surface=PhotoScan.HeightField,
            interpolation=PhotoScan.EnabledInterpolation,
            face_count=PhotoScan.HighFaceCount,
            source=PhotoScan.DenseCloudata,
            classes=[2]
)

chunk.buildUV(mapping=PhotoScan.AdaptiveOrthophotoMapping)
chunk.buildTexture(size=2048)

chunk.exportModel(
            output_file,
            format=PhotoScan.ModelFormat.ModelFormatDXF_3DF,
            texture=False,
            projection=chunk.crs
        )

We haven't submitted the crash report. What is the proper process for submitting these reports? Is there a way to configure PhotoScan to automatically submit crash logs to you when this happens?

We noticed that on the same project, exporting the DXF from the menu completes in half a second, making what we would expect to be the same call through the Python API takes upwards of an hour for the exact same chunk.

Is there something wrong with the way we're calling export Model?

We also stumbled upon a peculiar behaviour where specifying the callback function parameter in the export Model function causes it to take an order of magnitude longer than calling the function without the callback.

IE: The command below completes in a second for our test case

chunk.exportModel('test.dxf',
    format=PhotoScan.ModelFormat.ModelFormatDXF_3DF,
    texture=False)

While this command takes >10 seconds

chunk.exportModel('test.dxf',
    format=PhotoScan.ModelFormat.ModelFormatDXF_3DF,
    texture=False,
    projection=chunk.crs, progress=lambda arg: print(arg))

Is it possible that the callback is being called too frequently? We really only need this every few seconds or so.

Cheers,

J

[perh]

Last 200 lines of log file when PhotoScan crashed during buildTexture:

Code: [Select]

2017-10-10 01:05:18 loaded partition in 0.323837 sec
2017-10-10 01:05:19 boundaries extracted in 0.125014 sec
2017-10-10 01:05:21 46 images blended in 2.4501 sec
2017-10-10 01:05:22 loaded partition in 0.322988 sec
2017-10-10 01:05:22 boundaries extracted in 0.124823 sec
2017-10-10 01:05:24 43 images blended in 2.30742 sec
2017-10-10 01:05:25 loaded partition in 0.322841 sec
2017-10-10 01:05:25 boundaries extracted in 0.124454 sec
2017-10-10 01:05:27 47 images blended in 2.05775 sec
2017-10-10 01:05:28 loaded partition in 0.323281 sec
2017-10-10 01:05:28 boundaries extracted in 0.124903 sec
2017-10-10 01:05:30 51 images blended in 1.893 sec
2017-10-10 01:05:31 loaded partition in 0.32534 sec
2017-10-10 01:05:31 boundaries extracted in 0.125329 sec
2017-10-10 01:05:33 46 images blended in 2.41532 sec
2017-10-10 01:05:34 loaded partition in 0.325599 sec
2017-10-10 01:05:34 boundaries extracted in 0.125401 sec
2017-10-10 01:05:37 49 images blended in 2.82381 sec
2017-10-10 01:05:38 loaded partition in 0.323099 sec
2017-10-10 01:05:38 boundaries extracted in 0.125349 sec
2017-10-10 01:05:41 33 images blended in 2.59012 sec
2017-10-10 01:05:42 loaded partition in 0.322311 sec
2017-10-10 01:05:42 boundaries extracted in 0.124083 sec
2017-10-10 01:05:44 29 images blended in 2.13652 sec
2017-10-10 01:05:45 loaded partition in 0.192991 sec
2017-10-10 01:05:45 boundaries extracted in 0.064604 sec
2017-10-10 01:05:46 12 images blended in 1.25942 sec
2017-10-10 01:05:46 loaded partition in 0.264992 sec
2017-10-10 01:05:46 boundaries extracted in 0.06042 sec
2017-10-10 01:05:48 11 images blended in 1.21669 sec
2017-10-10 01:05:48 loaded partition in 0.324129 sec
2017-10-10 01:05:49 boundaries extracted in 0.120959 sec
2017-10-10 01:05:51 26 images blended in 2.61377 sec
2017-10-10 01:05:52 loaded partition in 0.323654 sec
2017-10-10 01:05:52 boundaries extracted in 0.124713 sec
2017-10-10 01:05:55 35 images blended in 2.44235 sec
2017-10-10 01:05:55 loaded partition in 0.322156 sec
2017-10-10 01:05:56 boundaries extracted in 0.124584 sec
2017-10-10 01:05:58 35 images blended in 2.56172 sec
2017-10-10 01:05:59 loaded partition in 0.325876 sec
2017-10-10 01:05:59 boundaries extracted in 0.125663 sec
2017-10-10 01:06:01 39 images blended in 2.41611 sec
2017-10-10 01:06:02 loaded partition in 0.322701 sec
2017-10-10 01:06:02 boundaries extracted in 0.124678 sec
2017-10-10 01:06:05 44 images blended in 2.64016 sec
2017-10-10 01:06:06 loaded partition in 0.324725 sec
2017-10-10 01:06:06 boundaries extracted in 0.125318 sec
2017-10-10 01:06:09 46 images blended in 2.5321 sec
2017-10-10 01:06:09 loaded partition in 0.325298 sec
2017-10-10 01:06:09 boundaries extracted in 0.125685 sec
2017-10-10 01:06:12 36 images blended in 3.04288 sec
2017-10-10 01:06:13 loaded partition in 0.326041 sec
2017-10-10 01:06:13 boundaries extracted in 0.126402 sec
2017-10-10 01:06:16 31 images blended in 2.22605 sec
2017-10-10 01:06:17 loaded partition in 0.321166 sec
2017-10-10 01:06:17 boundaries extracted in 0.114088 sec
2017-10-10 01:06:19 21 images blended in 2.2957 sec
2017-10-10 01:06:20 loaded partition in 0.312135 sec
2017-10-10 01:06:20 boundaries extracted in 0.087652 sec
2017-10-10 01:06:22 11 images blended in 1.74657 sec
2017-10-10 01:06:22 loaded partition in 0.172427 sec
2017-10-10 01:06:22 boundaries extracted in 0.039468 sec
2017-10-10 01:06:23 6 images blended in 0.906151 sec
2017-10-10 01:06:24 loaded partition in 0.235148 sec
2017-10-10 01:06:24 boundaries extracted in 0.039798 sec
2017-10-10 01:06:25 6 images blended in 0.856284 sec
2017-10-10 01:06:25 loaded partition in 0.317056 sec
2017-10-10 01:06:25 boundaries extracted in 0.102007 sec
2017-10-10 01:06:28 22 images blended in 2.35049 sec
2017-10-10 01:06:29 loaded partition in 0.326386 sec
2017-10-10 01:06:29 boundaries extracted in 0.126723 sec
2017-10-10 01:06:32 39 images blended in 3.02588 sec
2017-10-10 01:06:33 loaded partition in 0.324286 sec
2017-10-10 01:06:33 boundaries extracted in 0.12549 sec
2017-10-10 01:06:35 40 images blended in 2.52857 sec
2017-10-10 01:06:36 loaded partition in 0.32423 sec
2017-10-10 01:06:36 boundaries extracted in 0.125119 sec
2017-10-10 01:06:39 41 images blended in 2.47245 sec
2017-10-10 01:06:39 loaded partition in 0.325634 sec
2017-10-10 01:06:40 boundaries extracted in 0.126556 sec
2017-10-10 01:06:42 44 images blended in 2.57505 sec
2017-10-10 01:06:43 loaded partition in 0.324333 sec
2017-10-10 01:06:43 boundaries extracted in 0.124955 sec
2017-10-10 01:06:46 35 images blended in 2.6066 sec
2017-10-10 01:06:46 loaded partition in 0.322474 sec
2017-10-10 01:06:47 boundaries extracted in 0.115073 sec
2017-10-10 01:06:49 21 images blended in 2.22622 sec
2017-10-10 01:06:50 loaded partition in 0.311916 sec
2017-10-10 01:06:50 boundaries extracted in 0.087603 sec
2017-10-10 01:06:51 11 images blended in 1.66811 sec
2017-10-10 01:06:52 loaded partition in 0.282016 sec
2017-10-10 01:06:52 boundaries extracted in 0.058508 sec
2017-10-10 01:06:53 8 images blended in 1.06973 sec
2017-10-10 01:06:54 loaded partition in 0.244763 sec
2017-10-10 01:06:54 boundaries extracted in 0.039051 sec
2017-10-10 01:06:55 4 images blended in 0.747249 sec
2017-10-10 01:06:55 loaded partition in 0.283971 sec
2017-10-10 01:06:55 boundaries extracted in 0.078916 sec
2017-10-10 01:06:57 14 images blended in 1.53097 sec
2017-10-10 01:06:58 loaded partition in 0.323664 sec
2017-10-10 01:06:58 boundaries extracted in 0.124408 sec
2017-10-10 01:07:01 31 images blended in 2.71231 sec
2017-10-10 01:07:01 loaded partition in 0.325883 sec
2017-10-10 01:07:02 boundaries extracted in 0.125164 sec
2017-10-10 01:07:04 44 images blended in 2.2819 sec
2017-10-10 01:07:05 loaded partition in 0.324262 sec
2017-10-10 01:07:05 boundaries extracted in 0.124905 sec
2017-10-10 01:07:07 36 images blended in 2.39065 sec
2017-10-10 01:07:08 loaded partition in 0.324226 sec
2017-10-10 01:07:08 boundaries extracted in 0.119692 sec
2017-10-10 01:07:11 26 images blended in 2.63257 sec
2017-10-10 01:07:12 loaded partition in 0.316681 sec
2017-10-10 01:07:12 boundaries extracted in 0.091715 sec
2017-10-10 01:07:14 16 images blended in 1.88768 sec
2017-10-10 01:07:14 loaded partition in 0.282522 sec
2017-10-10 01:07:14 boundaries extracted in 0.059574 sec
2017-10-10 01:07:15 9 images blended in 1.09061 sec
2017-10-10 01:07:16 loaded partition in 0.244313 sec
2017-10-10 01:07:16 boundaries extracted in 0.039465 sec
2017-10-10 01:07:17 4 images blended in 0.739621 sec
2017-10-10 01:07:17 loaded partition in 0.274289 sec
2017-10-10 01:07:18 boundaries extracted in 0.054759 sec
2017-10-10 01:07:18 8 images blended in 0.964798 sec
2017-10-10 01:07:19 loaded partition in 0.323544 sec
2017-10-10 01:07:19 boundaries extracted in 0.112496 sec
2017-10-10 01:07:22 21 images blended in 2.87063 sec
2017-10-10 01:07:23 loaded partition in 0.324221 sec
2017-10-10 01:07:23 boundaries extracted in 0.124561 sec
2017-10-10 01:07:26 31 images blended in 2.89248 sec
2017-10-10 01:07:27 loaded partition in 0.316944 sec
2017-10-10 01:07:27 boundaries extracted in 0.105281 sec
2017-10-10 01:07:29 20 images blended in 2.46093 sec
2017-10-10 01:07:30 loaded partition in 0.283129 sec
2017-10-10 01:07:30 boundaries extracted in 0.067461 sec
2017-10-10 01:07:32 10 images blended in 1.33436 sec
2017-10-10 01:07:32 loaded partition in 0.245486 sec
2017-10-10 01:07:32 boundaries extracted in 0.04203 sec
2017-10-10 01:07:33 5 images blended in 0.8042 sec
2017-10-10 01:07:34 loaded partition in 0.17159 sec
2017-10-10 01:07:34 boundaries extracted in 0.024665 sec
2017-10-10 01:07:34 4 images blended in 0.560928 sec
2017-10-10 01:07:35 loaded partition in 0.201201 sec
2017-10-10 01:07:35 boundaries extracted in 0.052006 sec
2017-10-10 01:07:36 7 images blended in 1.14158 sec
2017-10-10 01:07:36 loaded partition in 0.201238 sec
2017-10-10 01:07:36 boundaries extracted in 0.060256 sec
2017-10-10 01:07:38 11 images blended in 1.24897 sec
2017-10-10 01:07:38 loaded partition in 0.180971 sec
2017-10-10 01:07:38 boundaries extracted in 0.035454 sec
2017-10-10 01:07:39 6 images blended in 0.718072 sec
2017-10-10 01:07:39 orthomosaic updated in 216.312 sec
2017-10-10 01:07:39 Finished processing in 498.219 sec (exit code 1)
2017-10-10 01:07:39 {
2017-10-10 01:07:39   "command": "exportOrtho",
2017-10-10 01:07:39   "params": {
2017-10-10 01:07:39     "jpeg": true
2017-10-10 01:07:39   }
2017-10-10 01:07:39 }
2017-10-10 01:07:39 ExportRaster
2017-10-10 01:07:39 Exporting orthomosaic...
2017-10-10 01:07:39 generating 31431 x 47661 raster in 1 x 1 tiles
2017-10-10 01:08:55 Finished processing in 75.5577 sec (exit code 1)
2017-10-10 01:08:55 {
2017-10-10 01:08:55   "command": "buildModel",
2017-10-10 01:08:55   "params": {
2017-10-10 01:08:55     "classes": [
2017-10-10 01:08:55       2
2017-10-10 01:08:55     ],
2017-10-10 01:08:55     "faceCount": "high",
2017-10-10 01:08:55     "interpolation": "enabled",
2017-10-10 01:08:55     "surfaceType": "heightField"
2017-10-10 01:08:55   }
2017-10-10 01:08:55 }
2017-10-10 01:08:55 BuildModel: surface type = Height field, source data = Dense cloud, face count = High, interpolation = Enabled
2017-10-10 01:08:57 Generating mesh...
2017-10-10 01:08:57 generating 14158x7733 grid (0.00786022 resolution)
2017-10-10 01:08:57 rasterizing dem... done in 5.86531 sec
2017-10-10 01:09:03 filtering dem... done in 2.75937 sec
2017-10-10 01:09:08 constructed triangulation from 204609 vertices, 409212 faces
2017-10-10 01:09:14 grid interpolated in 8.08164 sec
2017-10-10 01:10:58  6733274 points 13466003 faces done in 102.692 sec
2017-10-10 01:11:00 Calculating vertex colors...
2017-10-10 01:11:00 processing nodes...  done in 2.59545 sec
2017-10-10 01:14:39  done in 216.13 sec
2017-10-10 01:14:45 Finished processing in 343.831 sec (exit code 1)
2017-10-10 01:14:45 {
2017-10-10 01:14:45   "command": "buildTexture",
2017-10-10 01:14:45   "params": {
2017-10-10 01:14:45     "textureSize": 2048
2017-10-10 01:14:45   }
2017-10-10 01:14:45 }
2017-10-10 01:14:45 BuildUV: mapping mode = Adaptive orthophoto, texture count = 1
2017-10-10 01:14:45 Parameterizing texture atlas...
2017-10-10 01:18:51 Finished processing in 239.522 sec (exit code 1)
2017-10-10 01:18:51 BuildTexture: blending mode = Mosaic, texture size = 2048
2017-10-10 01:18:51 Blending textures...
2017-10-10 01:18:51 calculating mesh connectivity... done in 6.10189 sec
2017-10-10 01:20:34  done in 96.8415 sec
2017-10-10 01:22:29  done in 115.36 sec

[perh]

Last 100 lines from the log file when PhotoScan during exportModel:

Code: [Select]

2017-10-10 00:48:49 58 images blended in 3.40945 sec
2017-10-10 00:48:50 loaded partition in 0.327223 sec
2017-10-10 00:48:50 boundaries extracted in 0.126394 sec
2017-10-10 00:48:53 98 images blended in 2.71615 sec
2017-10-10 00:48:54 loaded partition in 0.318027 sec
2017-10-10 00:48:54 boundaries extracted in 0.119314 sec
2017-10-10 00:48:57 60 images blended in 3.62204 sec
2017-10-10 00:48:58 loaded partition in 0.088216 sec
2017-10-10 00:48:58 boundaries extracted in 0.032681 sec
2017-10-10 00:48:59 23 images blended in 0.666995 sec
2017-10-10 00:48:59 loaded partition in 0.271577 sec
2017-10-10 00:48:59 boundaries extracted in 0.098142 sec
2017-10-10 00:49:02 54 images blended in 3.06632 sec
2017-10-10 00:49:03 loaded partition in 0.329007 sec
2017-10-10 00:49:03 boundaries extracted in 0.127393 sec
2017-10-10 00:49:08 86 images blended in 4.63768 sec
2017-10-10 00:49:09 loaded partition in 0.312484 sec
2017-10-10 00:49:09 boundaries extracted in 0.118796 sec
2017-10-10 00:49:13 52 images blended in 4.38822 sec
2017-10-10 00:49:14 loaded partition in 0.087115 sec
2017-10-10 00:49:14 boundaries extracted in 0.034294 sec
2017-10-10 00:49:15 21 images blended in 0.678282 sec
2017-10-10 00:49:15 loaded partition in 0.187167 sec
2017-10-10 00:49:15 boundaries extracted in 0.065141 sec
2017-10-10 00:49:17 25 images blended in 2.0593 sec
2017-10-10 00:49:18 loaded partition in 0.225337 sec
2017-10-10 00:49:18 boundaries extracted in 0.08038 sec
2017-10-10 00:49:20 42 images blended in 2.10475 sec
2017-10-10 00:49:20 loaded partition in 0.214422 sec
2017-10-10 00:49:20 boundaries extracted in 0.072778 sec
2017-10-10 00:49:23 28 images blended in 2.25044 sec
2017-10-10 00:49:23 loaded partition in 0.058683 sec
2017-10-10 00:49:23 boundaries extracted in 0.020845 sec
2017-10-10 00:49:24 11 images blended in 0.413144 sec
2017-10-10 00:49:24 orthomosaic updated in 61.1099 sec
2017-10-10 00:49:24 Finished processing in 161.236 sec (exit code 1)
2017-10-10 00:49:24 {
2017-10-10 00:49:24   "command": "exportOrtho",
2017-10-10 00:49:24   "params": {
2017-10-10 00:49:24     "jpeg": true
2017-10-10 00:49:24   }
2017-10-10 00:49:24 }
2017-10-10 00:49:24 ExportRaster
2017-10-10 00:49:24 Exporting orthomosaic...
2017-10-10 00:49:24 generating 19558 x 12974 raster in 1 x 1 tiles
2017-10-10 00:49:38 Finished processing in 14.4542 sec (exit code 1)
2017-10-10 00:49:38 {
2017-10-10 00:49:38   "command": "buildModel",
2017-10-10 00:49:38   "params": {
2017-10-10 00:49:38     "classes": [
2017-10-10 00:49:38       2
2017-10-10 00:49:38     ],
2017-10-10 00:49:38     "faceCount": "high",
2017-10-10 00:49:38     "interpolation": "enabled",
2017-10-10 00:49:38     "surfaceType": "heightField"
2017-10-10 00:49:38   }
2017-10-10 00:49:38 }
2017-10-10 00:49:38 BuildModel: surface type = Height field, source data = Dense cloud, face count = High, interpolation = Enabled
2017-10-10 00:49:39 Generating mesh...
2017-10-10 00:49:39 generating 6066x4076 grid (0.0114292 resolution)
2017-10-10 00:49:39 rasterizing dem... done in 1.52333 sec
2017-10-10 00:49:40 filtering dem... done in 0.639333 sec
2017-10-10 00:49:42 constructed triangulation from 70788 vertices, 141570 faces
2017-10-10 00:49:44 grid interpolated in 3.15977 sec
2017-10-10 00:50:10  1789061 points 3577673 faces done in 25.6196 sec
2017-10-10 00:50:11 Calculating vertex colors...
2017-10-10 00:50:11 processing nodes...  done in 0.685738 sec
2017-10-10 00:51:02  done in 50.8978 sec
2017-10-10 00:51:04 Finished processing in 84.2895 sec (exit code 1)
2017-10-10 00:51:04 {
2017-10-10 00:51:04   "command": "buildTexture",
2017-10-10 00:51:04   "params": {
2017-10-10 00:51:04     "textureSize": 2048
2017-10-10 00:51:04   }
2017-10-10 00:51:04 }
2017-10-10 00:51:04 BuildUV: mapping mode = Adaptive orthophoto, texture count = 1
2017-10-10 00:51:04 Parameterizing texture atlas...
2017-10-10 00:52:07 Finished processing in 61.0578 sec (exit code 1)
2017-10-10 00:52:07 BuildTexture: blending mode = Mosaic, texture size = 2048
2017-10-10 00:52:07 Blending textures...
2017-10-10 00:52:07 calculating mesh connectivity... done in 1.34856 sec
2017-10-10 00:52:43  done in 34.7547 sec
2017-10-10 00:53:27  done in 43.9017 sec
2017-10-10 00:58:22 postprocessing texture... done in 0.123304 sec
2017-10-10 00:58:22 applying texture... done in 2.25628 sec
2017-10-10 00:58:30 Finished processing in 377.24 sec (exit code 1)
2017-10-10 00:58:30 {
2017-10-10 00:58:30   "command": "exportModel",
2017-10-10 00:58:30   "params": {
2017-10-10 00:58:30     "cameras": false,
2017-10-10 00:58:30     "colours": false,
2017-10-10 00:58:30     "normals": false,
2017-10-10 00:58:30     "outputCrs": "LOCAL_CS[\"Local Coordinates (m)\",LOCAL_DATUM[\"Local Datum\",0],UNIT[\"metre\",1,AUTHORITY[\"EPSG\",\"9001\"]]]",
2017-10-10 00:58:30     "outputFormat": "obj",
2017-10-10 00:58:30     "texture": true
2017-10-10 00:58:30   }
2017-10-10 00:58:30 }
2017-10-10 00:58:30 ExportModel
2017-10-10 00:58:30 Saving 3D model...

[perh]

In following up on the progress callback mentioned above, we definitely do see it called *very* often. For a call to "exportModel" as an OBJ, an operation that takes on the order of 0.1 seconds when invoked without the progress callback in PhotoScan 1.3.3, the progress callback was called about 19340 times. The elapsed time is close to 2 seconds (as outlined in post #2). I tried this on PhotoScan 1.3.3, since there appears to be some further difference in 1.3.4 (as outlined in post #2).

Some further findings about the progress callback:

— buildTexture made 9300 calls to the progress callback (operation w/o callback takes a second or so)
— exportModel for the OBJ made 19340 calls to the progress callback (operation w/o callback takes less than 0.1 seconds)
— exportModel for the DXF made 1200 calls

As mentioned in post #4, the progress callback seems to significantly slow down operations. In our case, we log a progress update (using print) on each call. That could be a particularly expensive operation if it causes I/O to the log file. As an experiment, I expanded the status callback a little bit to only log at most once every ten seconds.

With that change, the time taken is within ±50% of when not supplying the callback, but we are experimenting with extremely tiny models so it is hard to say with more certainty than that.

This is the callback we are using:

Code: [Select]

def status_update(op_name):
    def inner(progress_pct):
        now = time.time()
        if now - globalz.last_status_update < STATUS_UPDATE_INTERVAL: return
        globalz.last_status_update = now
        print('%~ progress {} {} ~%'.format(op_name, progress_pct))

    return inner

We call it like this:

Code: [Select]

chunk.buildUV(
  mapping=PhotoScan.AdaptiveOrthophotoMapping,
  progress=status_update('buildUV')
)
Currently running some multi-hour tests on larger projects that were previously crashing consistently when supplying the callback – I have simply removed it for now. I do notice that PhotoScan uses a surprising amount of memory when exporting models from mid-sized (hundreds of photos) projects. This could potentially be because of the logging from the progress callback: the log files end up being many millions of lines and hundreds of megs of text – could the segmentation fault be related to filling up the console buffer? If I have time today I also want to run the same multi-hour tests again, but with the progress callback above that logs, but not as often.

[Alexey Pasumansky]

Hello perh,

Thank you for providing the additional information.

The overflow of the Console pane may lead to the crash in the version 1.3, we were observing something similar a few times with the huge amount of the output information. I think it should be fixed in 1.4, but currently your approach with reducing the callback frequency seems reasonable.

As for the high memory consumption, is it correct that is starts to raise on the start of the export operation? Can you provide some approximate numbers of the memory consumption peak (compared to the common state - before the export), model properties (i.e. number of polygons and texture atlas size) and also specify, if you are suing PSX or PSZ project format?

[perh]

Hi Alexey,

I do not have super-hard numbers on the memory consumption but I did see PhotoScan using 27 gigabytes of memory for a 200-photo project, which feels a bit on the high side. It could very well be the console pane content, because the memory consumption creeps upwards slowly during the whole process, which would be consistent with logging millions and millions of lines of text... I have now tried running a few multi-hour test runs (ranging from 50ish to a few hundred photos) both without supplying the progress callback, and supplying one that logs less often. In both tested versions (1.3.3 and 1.3.4), it seems like this did the trick. In other words: with the changes to the progress callback outlined in the previous post, PhotoScan does no longer crash. That little callback with a single print statement was the last thing we suspected, ironically!

We are using the PSX format. I did not record the peak memory consumption for either run, and remember only the 27-gigabyte number above. I do know that there was no swap usage, though, and the machines we used had 60 gigs of memory. I am not sure about the number of polygons or the texture atlas size, but the models should be fairly small. I am seeing numbers like:

Code: [Select]

(one project)
constructed triangulation from 70788 vertices, 141570 faces
 1789061 points 3577673 faces done in 25.6196 sec

(another project)
constructed triangulation from 204609 vertices, 409212 faces
 6733274 points 13466003 faces done in 102.692 sec

You mention version 1.4. How far along is that and how does the release schedule look? Will we see more preview builds before the stable release, do you think?

[Alexey Pasumansky]

Hello perh,

Version 1.4.0 is available for beta-testing already:
http://www.agisoft.com/forum/index.php?topic=7730.0
But the pre-release version is not recommended for production jobs, due to the possible issues.

And regarding the memory issue, in some cases on Linux the used memory may also contain the cache, not only resources used by the current operation.