Do the task configuration info pop-up tips in the WebODM GUI correctly list the processing stage order?
E.g. the tooltips for “rerun-from” and “end-with” suggest this is the sequence, but it seems to me that the merge stage would actually happen somewhere near the end:
dataset
split
merge
opensfm
openmvs
odm_filterpoints
odm_meshing
mvs_texturing
odm_georeferencing
odm_dem
odm_orthophoto
odm_report
odm_postprocess
This predates a few changes, but it should be mostly representative still.
If I understand correctly, the flow should be like this (and agrees with the tooltip):
Load Dataset
Dataset Split
Dataset Merge
Stucture From Motion
Multi-View Stereo
Point Cloud Filtering
Meshing
Texturing
Georeferencing
DEM Processing
Orthophoto Processing
Report
Post-Processing
The progress values here seem to confirm this flow:
I could have it wrong, however 
Thanks Saijin, I guess I don’t understand what is being done by the “merge” stage…because what would be the point of splitting the dataset and merging those parts back together again without doing any processing between those stages?
If you aren’t using split-merge, those stages aren’t relevant:
https://docs.opendronemap.org/large/
In which processing stage would this log message (below) occur?
Geometric-consistent estimated depth-maps 206 (6.32%, 21m47s, ETA 5h23m)…
And what do the two time references mean, time taken for this stage so far and estimated time to complete the stage?
Correct: time so far and estimated time left. This is in the OpenMVS / depthmap creation stage.
Thanks Steve, much appreciated.
A related question - I had a set of 3265 photos being processed and it reached this point, and after another 20+ hours it hadn’t progressed any further:
Fused depth-maps 3244 (99.51%,2d30m30s, ETA 14m)…
At what stage of processing was this, and how would you check if the processing had gotten stuck there?
That stage can take a long time. Can you monitor disk I/O? you should see it writing out to disk during this stage.
Thanks Saijin, I’ll look at the disk I/O on my next test.
I’m confused about the order of the processing stages as listed above because what I’m seeing in practice appears inconsistent with the above sequence.
I am going through the processing stages one at a time using “rerun_from” and “end_with” so I can measure the resource consumption and processing time of each stage.
First I ran the dataset loading and opensfm stages using “rerun_from:dataset” and “end_with:opensfm”.
Next I ran the openmvs stage (rerun_from:openMVS and end_with:openMVS). In the logs it indicated that the previous stage had been completed and it was proceeding with the openmvs stage:
[INFO] Running opensfm stage
[WARNING] /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/image_list.txt already exists, not rerunning OpenSfM setup
[WARNING] /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/exif already exists, not rerunning photo to metadata
[WARNING] Detect features already done: /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/features exists
[WARNING] Match features already done: /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/matches exists
[WARNING] Found a valid OpenSfM tracks file in: /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/tracks.csv
[WARNING] Found a valid OpenSfM reconstruction file in: /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/reconstruction.json
[INFO] Already extracted cameras
[INFO] Export reconstruction stats
[WARNING] Found existing reconstruction stats /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/stats/stats.json
[WARNING] Will skip exporting /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/reconstruction.geocoords.json
[INFO] Undistorting /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm …
[WARNING] Already undistorted (nominal)
[WARNING] Found a valid OpenSfM NVM reconstruction file in: /var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm/undistorted/reconstruction.nvm
[INFO] Finished opensfm stage
[INFO] Running openmvs stage
[INFO] running “/code/SuperBuild/install/bin/opensfm/bin/opensfm” export_openmvs “/var/www/data/4aec0e31-26a6-4f6b-99d6-6d1c9a85045d/opensfm”
Now I’m running the odm_filterpoints stage (rerun_from:odm_filterpoints and end_with:odm_filterpoints).
However, in the logs I noticed it started doing the processing from the opensfm stage all over again:
[INFO] Running opensfm stage
[WARNING] /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/image_list.txt already exists, not rerunning OpenSfM setup
[WARNING] /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/exif already exists, not rerunning photo to metadata
[WARNING] Detect features already done: /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/features exists
[WARNING] Match features already done: /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/matches exists
[WARNING] Found a valid OpenSfM tracks file in: /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/tracks.csv
[INFO] running “/code/SuperBuild/install/bin/opensfm/bin/opensfm” reconstruct “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm”
2022-04-23 23:59:40,482 INFO: Starting incremental reconstruction
2022-04-24 00:15:57,147 INFO: Starting reconstruction with EW1_DJI_0471.JPG and EW1_DJI_0513.JPG
2022-04-24 00:15:57,323 INFO: Two-view 5-points reconstruction inliers (transposed=False): 10106 / 10113
2022-04-24 00:16:01,641 INFO: Triangulated: 10106
2022-04-24 00:16:08,574 DEBUG: Ceres Solver Report: Iterations: 26, Initial cost: 2.480788e+03, Final cost: 6.057003e+02, Termination: CONVERGENCE
2022-04-24 00:16:08,774 INFO: Removed outliers: 96
2022-04-24 00:16:15,325 INFO: -------------------------------------------------------
2022-04-24 00:16:15,565 INFO: EW1_DJI_0470.JPG resection inliers: 5825 / 5827
2022-04-24 00:16:15,644 INFO: Adding EW1_DJI_0470.JPG to the reconstruction
2022-04-24 00:16:18,153 INFO: Re-triangulating
2022-04-24 00:16:25,768 DEBUG: Ceres Solver Report: Iterations: 61, Initial cost: 6.554288e+03, Final cost: 2.462796e+03, Termination: CONVERGENCE
2022-04-24 00:16:38,550 DEBUG: Ceres Solver Report: Iterations: 38, Initial cost: 3.677284e+03, Final cost: 2.519271e+03, Termination: CONVERGENCE
2022-04-24 00:16:39,002 INFO: Removed outliers: 182
2022-04-24 00:16:44,631 INFO: -------------------------------------------------------
…
I expected the logs would show it detected opensfm & openmvs were completed and start from odm_filterpoints.
Why has it gone all the way back to opensfm instead?
Update: “odm-filterpoints” processing failed after 127 hours with a “Cannot process dataset” error.
Below I’ve copied excerpts from the NodeODM log to show the stage start/end settings and the processing stages it actually performed.
It looks to me like it ignored the settings and repeated most of the openSFM processing and all of the open MVS processing before it started the odm-filterpoints stage, and the failure occurred there.
Unfortunately there is no timestamp on the [ERROR] message so I can’t see when it failed.
Log excerpts:
[INFO] Initializing ODM 2.8.2 - Sat Apr 23 23:57:56 2022
[INFO] ==============
…
[INFO] end_with: odm_filterpoints
…
[INFO] rerun_from: [‘odm_filterpoints’, ‘odm_meshing’, ‘mvs_texturing’, ‘odm_georeferencing’, ‘odm_dem’, ‘odm_orthophoto’, ‘odm_report’, ‘odm_postprocess’]
…
[INFO] ==============
[INFO] Running dataset stage
…
[INFO] Running opensfm stage
[WARNING] /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/image_list.txt already exists, not rerunning OpenSfM setup
[WARNING] /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/exif already exists, not rerunning photo to metadata
[WARNING] Detect features already done: /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/features exists
[WARNING] Match features already done: /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/matches exists
[WARNING] Found a valid OpenSfM tracks file in: /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/tracks.csv
[INFO] running “/code/SuperBuild/install/bin/opensfm/bin/opensfm” reconstruct “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm”
2022-04-24 00:15:57,147 INFO: Starting reconstruction with EW1_DJI_0471.JPG and EW1_DJI_0513.JPG
…
2022-04-24 22:21:48,742 INFO: NS1_DJI_0880.JPG resection inliers: 13 / 13
2022-04-24 22:21:48,759 INFO: Adding NS1_DJI_0880.JPG to the reconstruction
2022-04-24 22:21:59,689 INFO: -------------------------------------------------------
2022-04-24 22:21:59,703 INFO: Some images can not be added
2022-04-24 22:21:59,703 INFO: -------------------------------------------------------
2022-04-24 22:21:59,729 INFO: Shots and/or GCPs are well-conditioned. Using naive 3D-3D alignment.
2022-04-24 22:21:59,745 INFO: Applying global bias with scale 0.99985 / translation [-0.31308247 -0.4075447 -0.05927073] / rotation [-0.00747817 0.00555329 0.00032779]
2022-04-24 22:24:39,205 WARNING: Cannot compensate some shots, GPS bias won’t be compensated.
2022-04-25 00:00:09,591 DEBUG: Ceres Solver Report: Iterations: 43, Initial cost: 3.521685e+06, Final cost: 1.945988e+06, Termination: CONVERGENCE
2022-04-25 00:04:16,654 INFO: Removed outliers: 32151
2022-04-25 00:07:21,070 INFO: Reconstruction 0: 3261 images, 8702116 points
2022-04-25 00:07:21,070 INFO: 1 partial reconstructions in total.
[INFO] Export reconstruction stats
[INFO] running “/code/SuperBuild/install/bin/opensfm/bin/opensfm” compute_statistics --diagram_max_points 100000 “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm”
…
[INFO] running “/code/SuperBuild/install/bin/opensfm/bin/opensfm” export_geocoords --reconstruction --proj “+proj=utm +zone=56 +south +datum=WGS84 +units=m +no_defs +type=crs” --offset-x 281598.0 --offset-y 6135789.0 “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm”
[INFO] Updating /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/config.yaml
[INFO] undistorted_image_max_size: 5472
[INFO] Undistorting /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm …
2022-04-25 01:53:14,826 DEBUG: Undistorting image EW1_DJI_0450.JPG
…
[INFO] running “/code/SuperBuild/install/bin/opensfm/bin/opensfm” export_visualsfm --points “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm”
[INFO] Finished opensfm stage
[INFO] Running openmvs stage
[INFO] running “/code/SuperBuild/install/bin/opensfm/bin/opensfm” export_openmvs “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm”
[INFO] Depthmap resolution set to: 2736px
[INFO] Running dense reconstruction. This might take a while.
[INFO] Estimating depthmaps
[INFO] nvidia-smi detected
[INFO] running “/code/SuperBuild/install/bin/OpenMVS/DensifyPointCloud” “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/scene.mvs” --resolution-level 1 --min-resolution 2736 --max-resolution 5472 --max-threads 40 --number-views-fuse 2 -w “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/depthmaps” -v 0
09:03:09 [App ] Build date: Apr 5 2022, 21:20:36
09:03:09 [App ] CPU: Intel(R) Xeon(R) CPU E5-2680 v2 @ 2.80GHz (40 cores)
09:03:09 [App ] RAM: 503.85GB Physical Memory 1.50TB Virtual Memory
09:03:09 [App ] OS: Linux 5.13.0-39-generic (x86_64)
09:03:09 [App ] SSE & AVX compatible CPU & OS detected
09:03:09 [App ] Command line: /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/scene.mvs --resolution-level 1 --min-resolution 2736 --max-resolution 5472 --max-threads 40 --number-views-fuse 2 -w /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/depthmaps -v 0
09:04:58 [App ] Preparing images for dense reconstruction completed: 3261 images (1m41s384ms)
09:06:07 [App ] Selecting images for dense reconstruction completed: 3261 images (1m8s371ms)
Estimated depth-maps 1 (0.03%, 3s, ETA 0ms)…
…
Estimated depth-maps 3261 (100%, 2h42m49s344ms)
…
Geometric-consistent estimated depth-maps 1 (0.03%, 3s, ETA 0ms)…
…
Geometric-consistent estimated depth-maps 3261 (100%, 2h2m16s458ms)
Geometric-consistent estimated depth-maps 1 (0.03%, 3s, ETA 0ms)…
…
Geometric-consistent estimated depth-maps 3261 (100%, 2h3m38s214ms)
Geometric-consistent estimated depth-maps 1 (0.03%, 4s, ETA 0ms)…
…
Geometric-consistent estimated depth-maps 3261 (100%, 2h4m4s166ms)
Filtered depth-maps 1 (0.03%, 58m44s, ETA 0ms)…
…
Filtered depth-maps 3261 (100%, 2h22m59s382ms)
Fused depth-maps 0 (0.00%, 18s, ETA 0ms)…
…
Fused depth-maps 3259 (100%, 2d32m26s992ms)
16:24:35 [App ] Densifying point-cloud completed: 2602702887 points (3d7h21m18s336ms)
01:51:37 [App ] MEMORYINFO: {
01:51:42 [App ] VmPeak: 1561255968 kB
01:51:42 [App ] VmSize: 1303356744 kB
01:51:42 [App ] } ENDINFO
[INFO] running “/code/SuperBuild/install/bin/OpenMVS/DensifyPointCloud” --filter-point-cloud -1 -i “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/scene_dense.mvs” -v 0
02:05:59 [App ] Build date: Apr 5 2022, 21:20:36
02:05:59 [App ] CPU: Intel(R) Xeon(R) CPU E5-2680 v2 @ 2.80GHz (40 cores)
02:05:59 [App ] RAM: 503.85GB Physical Memory 1.50TB Virtual Memory
02:05:59 [App ] OS: Linux 5.13.0-39-generic (x86_64)
02:05:59 [App ] SSE & AVX compatible CPU & OS detected
02:05:59 [App ] Command line: --filter-point-cloud -1 -i /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/scene_dense.mvs -v 0
Point visibility checks 1293477 (0.05%, 3s, ETA 0ms)…
…
Point visibility checks 2602702887 (100%, 2h17m33s69ms)
06:53:50 [App ] MEMORYINFO: {
06:53:50 [App ] VmPeak: 920108648 kB
06:53:50 [App ] VmSize: 882317684 kB
06:53:50 [App ] } ENDINFO
[INFO] Finished openmvs stage
[INFO] Running odm_filterpoints stage
…
[INFO] Filtering /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/scene_dense_dense_filtered.ply (statistical, meanK 16, standard deviation 2.5)
…
[INFO] running “/code/SuperBuild/install/bin/FPCFilter” --input “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/scene_dense_dense_filtered.ply” --output “/var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/odm_filterpoints/point_cloud.ply” --concurrency 40 --verbose --meank 16 --std 2.5 --boundary “/tmp/tmpy7p__kgz.boundary.json”
*** FPCFilter - v0.1 ***
?> Parameters:
input = /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/opensfm/undistorted/openmvs/scene_dense_dense_filtered.ply
output = /var/www/data/6a0bb5da-51f1-47ff-aeda-7a6e5bba8e30/odm_filterpoints/point_cloud.ply
std = 2.5
meanK = 16
boundary = 146 polygon vertexes
concurrency = 40
verbose = yes
→ Setting num_threads to 40
→ Cropping
Error: vector::reserve
===== Dumping Info for Geeks (developers need this to fix bugs) =====
Child returned 1
Traceback (most recent call last):
File “/code/stages/odm_app.py”, line 94, in execute
self.first_stage.run()
File “/code/opendm/types.py”, line 346, in run
self.next_stage.run(outputs)
File “/code/opendm/types.py”, line 346, in run
self.next_stage.run(outputs)
File “/code/opendm/types.py”, line 346, in run
self.next_stage.run(outputs)
[Previous line repeated 2 more times]
File “/code/opendm/types.py”, line 327, in run
self.process(self.args, outputs)
File “/code/stages/odm_filterpoints.py”, line 39, in process
point_cloud.filter(inputPointCloud, tree.filtered_point_cloud,
File “/code/opendm/point_cloud.py”, line 106, in filter
system.run(‘“%s” %s’ % (context.fpcfilter_path, " ".join(args)))
File “/code/opendm/system.py”, line 106, in run
raise SubprocessException(“Child returned {}”.format(retcode), retcode)
opendm.system.SubprocessException: Child returned 1
===== Done, human-readable information to follow… =====
[ERROR] Uh oh! Processing stopped because of strange values in the reconstruction. This is often a sign that the input data has some issues or the software cannot deal with it. Have you followed best practices for data acquisition? See Flying Tips — OpenDroneMap 3.1.7 documentation
This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.
