Skip to content

Instantly share code, notes, and snippets.

@NikolausDemmel

NikolausDemmel/final-13682 sparse_schur cxsparse

Created October 30, 2020 21:43
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save NikolausDemmel/9c7f39f8a46e57dd04d9ba8796ebd1ca to your computer and use it in GitHub Desktop.
Save NikolausDemmel/9c7f39f8a46e57dd04d9ba8796ebd1ca to your computer and use it in GitHub Desktop.
Download ZIP
BAL logs ceres
Raw
final-13682 sparse_schur cxsparse
$ /usr/bin/time -v ./bin/bundle_adjuster -use_quaternions -use_local_parameterization -num_threads 12 -num_iterations 20 -linear_solver sparse_schur -input problem-13682-4456117-pre.txt -v 3 -logtostderr -sparse_linear_algebra_library cx_sparse
I1030 18:13:42.591603 4171415 bal_problem.cc:85] Header: 13682 4456117 28987644
I1030 18:14:11.254379 4171415 bal_problem.cc:276] median: 00-1.2963 -0.297856 001.84581
I1030 18:14:11.254501 4171415 bal_problem.cc:277] median absolute deviation: 13.1983
I1030 18:14:11.254508 4171415 bal_problem.cc:278] scale: 7.57676
I1030 18:16:06.547497 4171415 wall_time.cc:84]
ComputeStableSchurOrdering
Delta Cumulative
CreateHessianGraph : 29.59815 29.59815
Preordering : 0.92089 30.51904
StableIndependentSet : 26.31114 56.83018
ConstantParameterBlocks : 0.34523 57.17541
Total : 15.52985 72.70526
I1030 18:16:25.854427 4171415 block_sparse_matrix.cc:80] Allocating values array with 5565627648 bytes.
I1030 18:16:25.931778 4171415 detect_structure.cc:75] Dynamic e block size because the block size changed from 3 to 9
I1030 18:16:25.931802 4171415 detect_structure.cc:95] Dynamic f block size because the block size changed from 9 to 3
I1030 18:16:26.034524 4171415 detect_structure.cc:113] Schur complement static structure <2,-1,-1>.
iter cost cost_change |gradient| |step| tr_ratio tr_radius ls_iter iter_time total_time
0 1.126372e+09 0.00e+00 3.02e+15 0.00e+00 0.00e+00 1.00e+04 0 2.16e+01 1.22e+02
I1030 18:21:23.687712 4171415 block_random_access_sparse_matrix.cc:78] Matrix Size [123327,123327] 1059153156
I1030 18:21:47.137743 4171415 detect_structure.cc:75] Dynamic e block size because the block size changed from 3 to 9
I1030 18:21:47.137776 4171415 detect_structure.cc:95] Dynamic f block size because the block size changed from 9 to 3
I1030 18:21:47.438536 4171415 detect_structure.cc:113] Schur complement static structure <2,-1,-1>.
I1030 18:27:15.738044 4171415 compressed_row_sparse_matrix.cc:210] # of rows: 123327 # of columns: 123327 num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:27:21.530030 4171415 compressed_row_sparse_matrix.cc:169] # of rows: 123327 # of columns: 123327 max_num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:30:21.882190 4171415 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 301.19766 301.19766
Eliminate : 131.35385 432.55151
ReducedSolve : 379.82714 812.37864
Total : 0.00003 812.37867
W1030 18:30:21.882243 4171415 levenberg_marquardt_strategy.cc:116] Linear solver failure. Failed to compute a step: CXSparse Failure : Numeric factorization failed.
1 1.126372e+09 0.00e+00 3.02e+15 0.00e+00 0.00e+00 5.00e+03 1 8.14e+02 9.36e+02
I1030 18:35:47.404356 4171415 compressed_row_sparse_matrix.cc:210] # of rows: 123327 # of columns: 123327 num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:35:53.121943 4171415 compressed_row_sparse_matrix.cc:169] # of rows: 123327 # of columns: 123327 max_num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:37:59.742497 4171415 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.01863 0.01863
Eliminate : 135.90355 135.92219
ReducedSolve : 321.81356 457.73574
Total : 0.00003 457.73577
W1030 18:37:59.742537 4171415 levenberg_marquardt_strategy.cc:116] Linear solver failure. Failed to compute a step: CXSparse Failure : Numeric factorization failed.
2 1.126372e+09 0.00e+00 3.02e+15 0.00e+00 0.00e+00 1.25e+03 1 4.58e+02 1.39e+03
I1030 18:43:27.275959 4171415 compressed_row_sparse_matrix.cc:210] # of rows: 123327 # of columns: 123327 num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:43:33.134873 4171415 compressed_row_sparse_matrix.cc:169] # of rows: 123327 # of columns: 123327 max_num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:45:36.914760 4171415 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.01847 0.01847
Eliminate : 134.83238 134.85086
ReducedSolve : 322.18619 457.03705
Total : 0.00002 457.03707
W1030 18:45:36.914805 4171415 levenberg_marquardt_strategy.cc:116] Linear solver failure. Failed to compute a step: CXSparse Failure : Numeric factorization failed.
3 1.126372e+09 0.00e+00 3.02e+15 0.00e+00 0.00e+00 1.56e+02 1 4.57e+02 1.85e+03
I1030 18:51:00.993712 4171415 compressed_row_sparse_matrix.cc:210] # of rows: 123327 # of columns: 123327 num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:51:06.688694 4171415 compressed_row_sparse_matrix.cc:169] # of rows: 123327 # of columns: 123327 max_num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:53:06.205868 4171415 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.01839 0.01839
Eliminate : 132.37467 132.39307
ReducedSolve : 316.77557 449.16863
Total : 0.00003 449.16866
W1030 18:53:06.205925 4171415 levenberg_marquardt_strategy.cc:116] Linear solver failure. Failed to compute a step: CXSparse Failure : Numeric factorization failed.
4 1.126372e+09 0.00e+00 3.02e+15 0.00e+00 0.00e+00 9.77e+00 1 4.49e+02 2.30e+03
I1030 18:58:28.186686 4171415 compressed_row_sparse_matrix.cc:210] # of rows: 123327 # of columns: 123327 num_nonzeros: 1059153156. Allocating 12710331184
I1030 18:58:33.892220 4171415 compressed_row_sparse_matrix.cc:169] # of rows: 123327 # of columns: 123327 max_num_nonzeros: 1059153156. Allocating 12710331184
I1030 19:00:31.087916 4171415 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.01821 0.01821
Eliminate : 131.45357 131.47178
ReducedSolve : 313.28271 444.75449
Total : 0.00003 444.75452
W1030 19:00:31.087983 4171415 levenberg_marquardt_strategy.cc:116] Linear solver failure. Failed to compute a step: CXSparse Failure : Numeric factorization failed.
E1030 19:00:31.087999 4171415 trust_region_minimizer.cc:92] Terminating: Number of consecutive invalid steps more than Solver::Options::max_num_consecutive_invalid_steps: 5
Solver Summary (v 2.0.0-eigen-(3.3.4)-lapack-suitesparse-(5.1.2)-cxsparse-(3.1.9)-eigensparse-no_openmp)
Original Reduced
Parameter blocks 4469799 4469799
Parameters 13505171 13505171
Effective parameters 13491489 13491489
Residual blocks 28987644 28987644
Residuals 57975288 57975288
Minimizer TRUST_REGION
Sparse linear algebra library CX_SPARSE
Trust region strategy LEVENBERG_MARQUARDT
Given Used
Linear solver SPARSE_SCHUR SPARSE_SCHUR
Threads 12 12
Linear solver ordering AUTOMATIC 4456038,13761
Schur structure 2,d,d 2,d,d
Cost:
Initial 1.126372e+09
Minimizer iterations 5
Successful steps 1
Unsuccessful steps 4
Time (in seconds):
Preprocessor 100.711413
Residual only evaluation 0.000000 (0)
Jacobian & residual evaluation 14.452976 (1)
Linear solver 2621.075032 (5)
Minimizer 2647.039983
Postprocessor 3.206938
Total 2750.958336
Termination: FAILURE (Number of consecutive invalid steps more than Solver::Options::max_num_consecutive_invalid_steps: 5)
Command being timed: "./bin/bundle_adjuster -use_quaternions -use_local_parameterization -num_threads 12 -num_iterations 20 -linear_solver sparse_schur -input problem-13682-4456117-pre.txt -v 3 -logtostderr -sparse_linear_algebra_library cx_sparse"
User time (seconds): 6909.34
System time (seconds): 272.11
Percent of CPU this job got: 252%
Elapsed (wall clock) time (h:mm:ss or m:ss): 47:27.84
Average shared text size (kbytes): 0
Average unshared data size (kbytes): 0
Average stack size (kbytes): 0
Average total size (kbytes): 0
Maximum resident set size (kbytes): 65697208
Average resident set size (kbytes): 0
Major (requiring I/O) page faults: 14
Minor (reclaiming a frame) page faults: 177224502
Voluntary context switches: 522877
Involuntary context switches: 539978
Swaps: 0
File system inputs: 4614
File system outputs: 0
Socket messages sent: 0
Socket messages received: 0
Signals delivered: 0
Page size (bytes): 4096
Exit status: 0
Raw
final-13682 sparse_schur suite_sparse
$ /usr/bin/time -v ./bin/bundle_adjuster -use_quaternions -use_local_parameterization -num_threads 12 -num_iterations 20 -linear_solver sparse_schur -input problem-13682-4456117-pre.txt -v 3 -logtostderr
I1030 14:27:02.481901 26942 bal_problem.cc:86] Header: 13682 4456117 28987644
I1030 14:27:22.467512 26942 bal_problem.cc:272] median: 00-1.2963 -0.297856 001.84581
I1030 14:27:22.467576 26942 bal_problem.cc:273] median absolute deviation: 13.1983
I1030 14:27:22.467581 26942 bal_problem.cc:274] scale: 7.57676
I1030 14:28:54.442145 26942 wall_time.cc:84]
ComputeStableSchurOrdering
Delta Cumulative
CreateHessianGraph : 23.17133 23.17133
Preordering : 0.84597 24.01730
StableIndependentSet : 23.35857 47.37587
ConstantParameterBlocks : 0.07206 47.44794
Total : 13.68200 61.12994
I1030 14:32:58.775877 26942 block_sparse_matrix.cc:81] Allocating values array with 5565627648 bytes.
I1030 14:32:58.779011 26942 detect_structure.cc:75] Dynamic e block size because the block size changed from 3 to 9
I1030 14:32:58.779022 26942 detect_structure.cc:94] Dynamic f block size because the block size changed from 9 to 3
I1030 14:32:58.914366 26942 detect_structure.cc:115] Schur complement static structure <2,-1,-1>.
iter cost cost_change |gradient| |step| tr_ratio tr_radius ls_iter iter_time total_time
0 1.126372e+09 0.00e+00 3.02e+15 0.00e+00 0.00e+00 1.00e+04 0 1.26e+01 3.24e+02
I1030 14:36:39.050156 26942 block_random_access_sparse_matrix.cc:76] Matrix Size [123327,123327] 1059153156
I1030 14:36:55.295533 26942 detect_structure.cc:75] Dynamic e block size because the block size changed from 3 to 9
I1030 14:36:55.295562 26942 detect_structure.cc:94] Dynamic f block size because the block size changed from 9 to 3
I1030 14:36:55.430985 26942 detect_structure.cc:115] Schur complement static structure <2,-1,-1>.
I1030 14:39:26.910647 26942 compressed_row_sparse_matrix.cc:211] # of rows: 123327 # of columns: 123327 num_nonzeros: 1059153156. Allocating 12710331184
I1030 14:39:30.841953 26942 compressed_row_sparse_matrix.cc:170] # of rows: 123327 # of columns: 123327 max_num_nonzeros: 1059153156. Allocating 12710331184
CHOLMOD error: problem too large. file: ../Supernodal/cholmod_super_symbolic.c line: 683
CHOLMOD version 3.0.11, May 4, 2016: Symbolic Analysis: status: ERROR, problem too large
Architecture: Linux
sizeof(int): 4
sizeof(SuiteSparse_long): 8
sizeof(void *): 8
sizeof(double): 8
sizeof(Int): 4 (CHOLMOD's basic integer)
sizeof(BLAS_INT): 4 (integer used in the BLAS)
Results from most recent analysis:
Cholesky flop count: 6.3495e+13
Nonzeros in L: 2.3931e+09
memory blocks in use: 4
memory in use (MB): 3.8
peak memory usage (MB): 4046.9
maxrank: update/downdate rank: 8
supernodal control: 1 40 (supernodal if flops/lnz >= 40)
nmethods: number of ordering methods to try: 1
method 0: natural
flop count: 6.3495e+13
nnz(L): 2.3931e+09
OK
I1030 14:40:09.128509 26942 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 224.46481 224.46481
Eliminate : 74.58617 299.05099
ReducedSolve : 116.80464 415.85563
Total : 0.00001 415.85564
W1030 14:40:09.128536 26942 levenberg_marquardt_strategy.cc:112] Linear solver fatal error: cholmod_analyze failed. error code: -3
E1030 14:40:09.128557 26942 trust_region_minimizer.cc:95] Terminating: Linear solver failed due to unrecoverable non-numeric causes. Please see the error log for clues.
Solver Summary (v 2.0.0-eigen-(3.3.4)-lapack-suitesparse-(5.1.2)-cxsparse-(3.1.9)-eigensparse-no_openmp)
Original Reduced
Parameter blocks 4469799 4469799
Parameters 13505171 13505171
Effective parameters 13491489 13491489
Residual blocks 28987644 28987644
Residuals 57975288 57975288
Minimizer TRUST_REGION
Sparse linear algebra library SUITE_SPARSE
Trust region strategy LEVENBERG_MARQUARDT
Given Used
Linear solver SPARSE_SCHUR SPARSE_SCHUR
Threads 12 12
Linear solver ordering AUTOMATIC 4456038,13761
Schur structure 2,d,d 2,d,d
Cost:
Initial 1.126372e+09
Minimizer iterations 1
Successful steps 1
Unsuccessful steps 0
Time (in seconds):
Preprocessor 311.727953
Residual only evaluation 0.000000 (0)
Jacobian & residual evaluation 9.046847 (1)
Linear solver 415.855676 (1)
Minimizer 430.967614
Postprocessor 1.834763
Total 744.530331
Termination: FAILURE (Linear solver failed due to unrecoverable non-numeric causes. Please see the error log for clues. )
I1030 14:40:17.714421 26942 ba_log.cc:164] Saved log for 1 iterations to ba_log.json.
Command being timed: "./bin/bundle_adjuster -use_quaternions -use_local_parameterization -num_threads 12 -num_iterations 20 -linear_solver sparse_schur -input problem-13682-4456117-pre.txt -v 3 -logtostderr"
User time (seconds): 1628.57
System time (seconds): 19.31
Percent of CPU this job got: 203%
Elapsed (wall clock) time (h:mm:ss or m:ss): 13:29.48
Average shared text size (kbytes): 0
Average unshared data size (kbytes): 0
Average stack size (kbytes): 0
Average total size (kbytes): 0
Maximum resident set size (kbytes): 57076424
Average resident set size (kbytes): 0
Major (requiring I/O) page faults: 8
Minor (reclaiming a frame) page faults: 17061638
Voluntary context switches: 12333
Involuntary context switches: 25241
Swaps: 0
File system inputs: 1864
File system outputs: 5208
Socket messages sent: 0
Socket messages received: 0
Signals delivered: 0
Page size (bytes): 4096
Exit status: 0
Raw
final-4585 sparse_schur suite_sparse
$ /usr/bin/time -v ./bin/bundle_adjuster -use_quaternions -use_local_parameterization -num_threads 12 -num_iterations 20 -linear_solver sparse_schur -input problem-4585-1324582-pre.txt -v 3 -logtostderr
I1030 15:14:07.725713 31072 bal_problem.cc:86] Header: 4585 1324582 9125125
I1030 15:14:13.940419 31072 bal_problem.cc:272] median: -18.0152 0177.401 -155.582
I1030 15:14:13.940476 31072 bal_problem.cc:273] median absolute deviation: 215.849
I1030 15:14:13.940479 31072 bal_problem.cc:274] scale: 0.463287
I1030 15:14:39.028265 31072 wall_time.cc:84]
ComputeStableSchurOrdering
Delta Cumulative
CreateHessianGraph : 6.06719 6.06719
Preordering : 0.24266 6.30985
StableIndependentSet : 6.34583 12.65568
ConstantParameterBlocks : 0.02116 12.67684
Total : 3.89596 16.57280
I1030 15:15:28.864043 31072 block_sparse_matrix.cc:81] Allocating values array with 1752024000 bytes.
I1030 15:15:28.865056 31072 detect_structure.cc:75] Dynamic e block size because the block size changed from 3 to 9
I1030 15:15:28.865067 31072 detect_structure.cc:94] Dynamic f block size because the block size changed from 9 to 3
I1030 15:15:28.905747 31072 detect_structure.cc:115] Schur complement static structure <2,-1,-1>.
iter cost cost_change |gradient| |step| tr_ratio tr_radius ls_iter iter_time total_time
0 6.028730e+08 0.00e+00 7.66e+08 0.00e+00 0.00e+00 1.00e+04 0 3.71e+00 7.17e+01
I1030 15:15:53.075543 31072 block_random_access_sparse_matrix.cc:76] Matrix Size [41304,41304] 141881463
I1030 15:15:55.077549 31072 detect_structure.cc:75] Dynamic e block size because the block size changed from 3 to 9
I1030 15:15:55.077579 31072 detect_structure.cc:94] Dynamic f block size because the block size changed from 9 to 3
I1030 15:15:55.118264 31072 detect_structure.cc:115] Schur complement static structure <2,-1,-1>.
I1030 15:16:15.126755 31072 compressed_row_sparse_matrix.cc:211] # of rows: 41304 # of columns: 41304 num_nonzeros: 141881463. Allocating 1702742776
I1030 15:16:15.643393 31072 compressed_row_sparse_matrix.cc:170] # of rows: 41304 # of columns: 41304 max_num_nonzeros: 141881463. Allocating 1702742776
CHOLMOD version 3.0.11, May 4, 2016: Symbolic Analysis: status: OK
Architecture: Linux
sizeof(int): 4
sizeof(SuiteSparse_long): 8
sizeof(void *): 8
sizeof(double): 8
sizeof(Int): 4 (CHOLMOD's basic integer)
sizeof(BLAS_INT): 4 (integer used in the BLAS)
Results from most recent analysis:
Cholesky flop count: 3.1986e+12
Nonzeros in L: 2.9869e+08
memory blocks in use: 11
memory in use (MB): 4.3
peak memory usage (MB): 546.2
maxrank: update/downdate rank: 8
supernodal control: 1 40 (supernodal if flops/lnz >= 40)
nmethods: number of ordering methods to try: 1
method 0: natural
flop count: 3.1986e+12
nnz(L): 2.9869e+08
OK
I1030 15:16:52.253965 31072 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 22.76792 22.76792
Eliminate : 10.37802 33.14594
ReducedSolve : 45.77480 78.92075
BackSubstitute : 0.25623 79.17698
Total : 0.00001 79.17699
1 8.185552e+06 5.95e+08 2.11e+08 7.05e+04 9.95e-01 3.00e+04 1 8.31e+01 1.55e+02
I1030 15:17:15.436269 31072 compressed_row_sparse_matrix.cc:211] # of rows: 41304 # of columns: 41304 num_nonzeros: 141881463. Allocating 1702742776
I1030 15:17:15.956331 31072 compressed_row_sparse_matrix.cc:170] # of rows: 41304 # of columns: 41304 max_num_nonzeros: 141881463. Allocating 1702742776
I1030 15:17:49.370455 31072 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00138 0.00138
Eliminate : 10.22576 10.22714
ReducedSolve : 42.60799 52.83513
BackSubstitute : 0.24365 53.07878
Total : 0.00001 53.07879
2 6.956849e+07 -6.14e+07 2.11e+08 2.96e+05 -2.05e+01 1.50e+04 1 5.41e+01 2.09e+02
I1030 15:18:09.525348 31072 compressed_row_sparse_matrix.cc:211] # of rows: 41304 # of columns: 41304 num_nonzeros: 141881463. Allocating 1702742776
I1030 15:18:10.041895 31072 compressed_row_sparse_matrix.cc:170] # of rows: 41304 # of columns: 41304 max_num_nonzeros: 141881463. Allocating 1702742776
I1030 15:18:45.308130 31072 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00134 0.00134
Eliminate : 10.23033 10.23167
ReducedSolve : 44.42265 54.65432
BackSubstitute : 0.26419 54.91851
Total : 0.00001 54.91852
3 1.665267e+08 -1.58e+08 2.11e+08 1.61e+05 -5.32e+01 3.75e+03 1 5.58e+01 2.65e+02
I1030 15:19:05.449429 31072 compressed_row_sparse_matrix.cc:211] # of rows: 41304 # of columns: 41304 num_nonzeros: 141881463. Allocating 1702742776
I1030 15:19:05.966735 31072 compressed_row_sparse_matrix.cc:170] # of rows: 41304 # of columns: 41304 max_num_nonzeros: 141881463. Allocating 1702742776
I1030 15:19:40.314409 31072 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00134 0.00134
Eliminate : 10.19756 10.19889
ReducedSolve : 43.50064 53.69953
BackSubstitute : 0.26988 53.96942
Total : 0.00001 53.96943
4 9.700996e+07 -8.88e+07 2.11e+08 4.48e+04 -3.04e+01 4.69e+02 1 5.48e+01 3.20e+02
I1030 15:20:00.416213 31072 compressed_row_sparse_matrix.cc:211] # of rows: 41304 # of columns: 41304 num_nonzeros: 141881463. Allocating 1702742776
I1030 15:20:00.935900 31072 compressed_row_sparse_matrix.cc:170] # of rows: 41304 # of columns: 41304 max_num_nonzeros: 141881463. Allocating 1702742776
I1030 15:20:34.466261 31072 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00133 0.00133
Eliminate : 10.17673 10.17806
ReducedSolve : 42.69245 52.87051
BackSubstitute : 0.26823 53.13875
Total : 0.00001 53.13876
5 3.206284e+10 -3.21e+10 2.11e+08 4.90e+03 -1.13e+04 2.93e+01 1 5.40e+01 3.74e+02
I1030 15:20:54.733700 31072 compressed_row_sparse_matrix.cc:211] # of rows: 41304 # of columns: 41304 num_nonzeros: 141881463. Allocating 1702742776
I1030 15:20:55.252210 31072 compressed_row_sparse_matrix.cc:170] # of rows: 41304 # of columns: 41304 max_num_nonzeros: 141881463. Allocating 1702742776
I1030 15:21:28.563598 31072 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00133 0.00133
Eliminate : 10.30332 10.30465
ReducedSolve : 42.46821 52.77286
BackSubstitute : 0.27486 53.04772
Total : 0.00001 53.04773
6 1.955217e+15 -1.96e+15 2.11e+08 9.91e+02 -7.17e+08 9.16e-01 1 5.39e+01 4.29e+02
I1030 15:21:48.752956 31072 compressed_row_sparse_matrix.cc:211] # of rows: 41304 # of columns: 41304 num_nonzeros: 141881463. Allocating 1702742776
I1030 15:21:49.275408 31072 compressed_row_sparse_matrix.cc:170] # of rows: 41304 # of columns: 41304 max_num_nonzeros: 141881463. Allocating 1702742776
I1030 15:22:23.558432 31072 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00139 0.00139
Eliminate : 10.21125 10.21264
ReducedSolve : 43.47375 53.68639
BackSubstitute : 0.26196 53.94835
Total : 0.00002 53.94837
7 1.649096e+20 -1.65e+20 2.11e+08 5.82e+02 -6.99e+13 1.43e-02 1 5.48e+01 4.84e+02
I1030 15:22:43.760897 31072 compressed_row_sparse_matrix.cc:211] # of rows: 41304 # of columns: 41304 num_nonzeros: 141881463. Allocating 1702742776
I1030 15:22:44.285629 31072 compressed_row_sparse_matrix.cc:170] # of rows: 41304 # of columns: 41304 max_num_nonzeros: 141881463. Allocating 1702742776
I1030 15:23:19.684317 31072 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00141 0.00141
Eliminate : 10.22748 10.22889
ReducedSolve : 44.56569 54.79457
BackSubstitute : 0.27964 55.07421
Total : 0.00001 55.07423
I1030 15:23:20.489104 31072 trust_region_minimizer.cc:731] Terminating: Parameter tolerance reached. Relative step_norm: 1.596039e-09 <= 1.000000e-08.
Solver Summary (v 2.0.0-eigen-(3.3.4)-lapack-suitesparse-(5.1.2)-cxsparse-(3.1.9)-eigensparse-no_openmp)
Original Reduced
Parameter blocks 1329167 1329167
Parameters 4019596 4019596
Effective parameters 4015011 4015011
Residual blocks 9125125 9125125
Residuals 18250250 18250250
Minimizer TRUST_REGION
Sparse linear algebra library SUITE_SPARSE
Trust region strategy LEVENBERG_MARQUARDT
Given Used
Linear solver SPARSE_SCHUR SPARSE_SCHUR
Threads 12 12
Linear solver ordering AUTOMATIC 1324565,4602
Schur structure 2,d,d 2,d,d
Cost:
Initial 6.028730e+08
Final 8.185552e+06
Change 5.946874e+08
Minimizer iterations 8
Successful steps 2
Unsuccessful steps 6
Time (in seconds):
Preprocessor 68.017320
Residual only evaluation 3.111239 (8)
Jacobian & residual evaluation 4.901655 (2)
Linear solver 456.353187 (8)
Minimizer 471.773831
Postprocessor 0.548905
Total 540.340056
Termination: CONVERGENCE (Parameter tolerance reached. Relative step_norm: 1.596039e-09 <= 1.000000e-08.)
I1030 15:23:22.537204 31072 ba_log.cc:164] Saved log for 8 iterations to ba_log.json.
Command being timed: "./bin/bundle_adjuster -use_quaternions -use_local_parameterization -num_threads 12 -num_iterations 20 -linear_solver sparse_schur -input problem-4585-1324582-pre.txt -v 3 -logtostderr"
User time (seconds): 3612.85
System time (seconds): 776.95
Percent of CPU this job got: 784%
Elapsed (wall clock) time (h:mm:ss or m:ss): 9:19.29
Average shared text size (kbytes): 0
Average unshared data size (kbytes): 0
Average stack size (kbytes): 0
Average total size (kbytes): 0
Maximum resident set size (kbytes): 16472380
Average resident set size (kbytes): 0
Major (requiring I/O) page faults: 42
Minor (reclaiming a frame) page faults: 10780956
Voluntary context switches: 188642
Involuntary context switches: 99199113
Swaps: 0
File system inputs: 947824
File system outputs: 13872
Socket messages sent: 0
Socket messages received: 0
Signals delivered: 0
Page size (bytes): 4096
Exit status: 0
Raw
final-93 sparse_schur suite_sparse
$ /usr/bin/time -v ./bin/bundle_adjuster -use_quaternions -use_local_parameterization -num_threads 12 -num_iterations 20 -linear_solver sparse_schur -input problem-93-61203-pre.txt -v 3 -logtostderr
I1030 15:31:46.076715 32593 bal_problem.cc:86] Header: 93 61203 287451
I1030 15:31:46.327425 32593 bal_problem.cc:272] median: 0-0.0381229 -0.00806813 000-1.62737
I1030 15:31:46.327477 32593 bal_problem.cc:273] median absolute deviation: 0.529999
I1030 15:31:46.327481 32593 bal_problem.cc:274] scale: 188.68
I1030 15:31:46.867005 32593 wall_time.cc:84]
ComputeStableSchurOrdering
Delta Cumulative
CreateHessianGraph : 0.14394 0.14394
Preordering : 0.00596 0.14990
StableIndependentSet : 0.09296 0.24287
ConstantParameterBlocks : 0.00097 0.24383
Total : 0.08384 0.32767
I1030 15:31:47.112416 32593 block_sparse_matrix.cc:81] Allocating values array with 55190592 bytes.
I1030 15:31:47.113934 32593 detect_structure.cc:115] Schur complement static structure <2,3,9>.
iter cost cost_change |gradient| |step| tr_ratio tr_radius ls_iter iter_time total_time
0 5.646900e+06 0.00e+00 3.79e+07 0.00e+00 0.00e+00 1.00e+04 0 1.20e-01 7.46e-01
I1030 15:31:47.340104 32593 block_random_access_sparse_matrix.cc:76] Matrix Size [837,837] 353970
I1030 15:31:47.344640 32593 detect_structure.cc:115] Schur complement static structure <2,3,9>.
I1030 15:31:47.472867 32593 compressed_row_sparse_matrix.cc:211] # of rows: 837 # of columns: 837 num_nonzeros: 353970. Allocating 4250992
I1030 15:31:47.474288 32593 compressed_row_sparse_matrix.cc:170] # of rows: 837 # of columns: 837 max_num_nonzeros: 353970. Allocating 4250992
CHOLMOD version 3.0.11, May 4, 2016: Symbolic Analysis: status: OK
Architecture: Linux
sizeof(int): 4
sizeof(SuiteSparse_long): 8
sizeof(void *): 8
sizeof(double): 8
sizeof(Int): 4 (CHOLMOD's basic integer)
sizeof(BLAS_INT): 4 (integer used in the BLAS)
Results from most recent analysis:
Cholesky flop count: 1.9581e+08
Nonzeros in L: 3.507e+05
memory blocks in use: 11
memory in use (MB): 0.0
peak memory usage (MB): 1.4
maxrank: update/downdate rank: 8
supernodal control: 1 40 (supernodal if flops/lnz >= 40)
nmethods: number of ordering methods to try: 1
method 0: natural
flop count: 1.9581e+08
nnz(L): 3.507e+05
OK
I1030 15:31:47.516364 32593 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.11403 0.11403
Eliminate : 0.08807 0.20210
ReducedSolve : 0.04697 0.24908
BackSubstitute : 0.01708 0.26615
Total : 0.00001 0.26616
1 1.561628e+05 5.49e+06 3.44e+06 1.21e+03 9.98e-01 3.00e+04 1 4.25e-01 1.18e+00
I1030 15:31:47.786115 32593 compressed_row_sparse_matrix.cc:211] # of rows: 837 # of columns: 837 num_nonzeros: 353970. Allocating 4250992
I1030 15:31:47.787204 32593 compressed_row_sparse_matrix.cc:170] # of rows: 837 # of columns: 837 max_num_nonzeros: 353970. Allocating 4250992
I1030 15:31:47.816427 32593 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00004 0.00004
Eliminate : 0.08606 0.08610
ReducedSolve : 0.03993 0.12603
BackSubstitute : 0.00998 0.13601
Total : 0.00001 0.13602
2 1.455589e+05 1.06e+04 4.19e+04 1.82e+02 1.00e+00 9.00e+04 1 2.72e-01 1.46e+00
I1030 15:31:48.067308 32593 compressed_row_sparse_matrix.cc:211] # of rows: 837 # of columns: 837 num_nonzeros: 353970. Allocating 4250992
I1030 15:31:48.067657 32593 compressed_row_sparse_matrix.cc:170] # of rows: 837 # of columns: 837 max_num_nonzeros: 353970. Allocating 4250992
I1030 15:31:48.097368 32593 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00004 0.00004
Eliminate : 0.08970 0.08974
ReducedSolve : 0.03985 0.12959
BackSubstitute : 0.00905 0.13864
Total : 0.00001 0.13865
3 1.455452e+05 1.38e+01 4.15e+03 3.50e+01 1.00e+00 2.70e+05 1 2.76e-01 1.74e+00
I1030 15:31:48.346000 32593 compressed_row_sparse_matrix.cc:211] # of rows: 837 # of columns: 837 num_nonzeros: 353970. Allocating 4250992
I1030 15:31:48.346351 32593 compressed_row_sparse_matrix.cc:170] # of rows: 837 # of columns: 837 max_num_nonzeros: 353970. Allocating 4250992
I1030 15:31:48.376546 32593 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00004 0.00004
Eliminate : 0.08553 0.08557
ReducedSolve : 0.04042 0.12599
BackSubstitute : 0.00955 0.13554
Total : 0.00001 0.13555
4 1.455451e+05 1.04e-01 9.15e+01 4.14e+00 1.01e+00 8.10e+05 1 2.72e-01 2.02e+00
I1030 15:31:48.625847 32593 compressed_row_sparse_matrix.cc:211] # of rows: 837 # of columns: 837 num_nonzeros: 353970. Allocating 4250992
I1030 15:31:48.626173 32593 compressed_row_sparse_matrix.cc:170] # of rows: 837 # of columns: 837 max_num_nonzeros: 353970. Allocating 4250992
I1030 15:31:48.656344 32593 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00004 0.00004
Eliminate : 0.08674 0.08678
ReducedSolve : 0.04136 0.12814
BackSubstitute : 0.00904 0.13718
Total : 0.00001 0.13719
5 1.455451e+05 2.50e-04 3.77e+00 2.19e-01 1.02e+00 2.43e+06 1 2.73e-01 2.30e+00
I1030 15:31:48.909001 32593 compressed_row_sparse_matrix.cc:211] # of rows: 837 # of columns: 837 num_nonzeros: 353970. Allocating 4250992
I1030 15:31:48.909340 32593 compressed_row_sparse_matrix.cc:170] # of rows: 837 # of columns: 837 max_num_nonzeros: 353970. Allocating 4250992
I1030 15:31:48.942134 32593 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00004 0.00004
Eliminate : 0.08928 0.08932
ReducedSolve : 0.04870 0.13802
BackSubstitute : 0.00503 0.14305
Total : 0.00001 0.14306
6 1.455451e+05 2.94e-07 2.53e-01 5.42e-03 1.04e+00 7.29e+06 1 2.89e-01 2.59e+00
I1030 15:31:49.197535 32593 compressed_row_sparse_matrix.cc:211] # of rows: 837 # of columns: 837 num_nonzeros: 353970. Allocating 4250992
I1030 15:31:49.197860 32593 compressed_row_sparse_matrix.cc:170] # of rows: 837 # of columns: 837 max_num_nonzeros: 353970. Allocating 4250992
I1030 15:31:49.231653 32593 wall_time.cc:84]
SchurComplementSolver::Solve
Delta Cumulative
Setup : 0.00004 0.00004
Eliminate : 0.08691 0.08695
ReducedSolve : 0.03765 0.12460
BackSubstitute : 0.01278 0.13738
Total : 0.00001 0.13739
I1030 15:31:49.284904 32593 trust_region_minimizer.cc:731] Terminating: Parameter tolerance reached. Relative step_norm: 5.656538e-09 <= 1.000000e-08.
Solver Summary (v 2.0.0-eigen-(3.3.4)-lapack-suitesparse-(5.1.2)-cxsparse-(3.1.9)-eigensparse-no_openmp)
Original Reduced
Parameter blocks 61296 61296
Parameters 184539 184539
Effective parameters 184446 184446
Residual blocks 287451 287451
Residuals 574902 574902
Minimizer TRUST_REGION
Sparse linear algebra library SUITE_SPARSE
Trust region strategy LEVENBERG_MARQUARDT
Given Used
Linear solver SPARSE_SCHUR SPARSE_SCHUR
Threads 12 12
Linear solver ordering AUTOMATIC 61203,93
Schur structure 2,3,9 2,3,9
Cost:
Initial 5.646900e+06
Final 1.455451e+05
Change 5.501355e+06
Minimizer iterations 7
Successful steps 7
Unsuccessful steps 0
Time (in seconds):
Preprocessor 0.625243
Residual only evaluation 0.183384 (7)
Jacobian & residual evaluation 0.495227 (7)
Linear solver 1.094395 (7)
Minimizer 2.178244
Postprocessor 0.017186
Total 2.820674
Termination: CONVERGENCE (Parameter tolerance reached. Relative step_norm: 5.656538e-09 <= 1.000000e-08.)
I1030 15:31:49.329564 32593 ba_log.cc:164] Saved log for 7 iterations to ba_log.json.
Command being timed: "./bin/bundle_adjuster -use_quaternions -use_local_parameterization -num_threads 12 -num_iterations 20 -linear_solver sparse_schur -input problem-93-61203-pre.txt -v 3 -logtostderr"
User time (seconds): 16.08
System time (seconds): 4.66
Percent of CPU this job got: 608%
Elapsed (wall clock) time (h:mm:ss or m:ss): 0:03.40
Average shared text size (kbytes): 0
Average unshared data size (kbytes): 0
Average stack size (kbytes): 0
Average total size (kbytes): 0
Maximum resident set size (kbytes): 279524
Average resident set size (kbytes): 0
Major (requiring I/O) page faults: 16
Minor (reclaiming a frame) page faults: 72562
Voluntary context switches: 42350
Involuntary context switches: 382252
Swaps: 0
File system inputs: 31224
File system outputs: 264
Socket messages sent: 0
Socket messages received: 0
Signals delivered: 0
Page size (bytes): 4096
Exit status: 0
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment