Message: botch in solve_out

A colleague of mine get’s the folowing error message:

Error at _cmdno 7525 executing “solve” command
(file ./AMPL/LIB/ampl_ELYRD_TimeLoop.run, line 66, offset 3368):

Bug: dc0 botch in solve_out

He told me, that his code worked so far using different input data (data sets). Now, this error appear using an additional data set which looks quite the same like the others - of course there are different data values. The code itself was only modified in a “cosmetic way”.
Line 66 simply contains the solve command.

Can anybody give some background information about this bug?

Best regards,
Lothar

We do not have any previous reports about this bug. Please ask your colleague to send us files that can be used to reproduce the bug on our computers. That will enable us to determine a fix (and perhaps also a temporary workaround).

If your colleague cannot provide the files right now, the following information will at least help us to get a start on fixing the problem:

  • The output from the AMPL command “option version;”.
  • The extra output that results when “option times 1, gentimes 1, show_stats 1;” is set before the solve command that causes the error.

Thank’s for your help.

Here is the output related the command “option version”:

'AMPL Version 20240606 (Linux-5.15.0-1064-azure, 64-bit)\
Licensed to ... <...> academic floating (localhost).\
Maintenance expires with version 20250430.\
Using license file "....lic".\

My colleague told me that the error appear after a runtime >24 hours. He is looking for the other output.

Unfortunatelly, providing the files seems not to be possible.

Best regards,
Lothar

Here are some additional information:

option gurobi_options 'outlev=1 BarHomogeneous=1 NumericFocus=3 Seed=123 CrossoverBasis=1 Method=2';

gurobi 11.03

I didn’t find a menu to upload a file, so please find the output of the command "option times 1, gentimes 1, show_stats 1;” in this way.

#				incremental	total
#phase		seconds		memory		memory
#execute	0.001187	356128		356128
### ampl_IEEOptTool_ELYRD.run:25(1193)   option ...
#execute	2.6e-05		0		356128
### ampl_IEEOptTool_ELYRD.run:33(1434)   let ...
#compile	4.2e-05		33128		389256
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 110        1e-06        1e-06            0  p_timer_0
## 111        3e-06        4e-06            0  p_timer
#genmod		1.4e-05		520		389776
#execute	4e-06		0		389776
### ampl_IEEOptTool_ELYRD.run:43(1842)   let ...
#compile	1.4e-05		0		389776
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 115        1e-06        1e-06            0  determine_ntme_block
## 116        2e-06        3e-06            0  storage_block_size
#genmod		9e-06		0		389776
#execute	4e-06		0		389776
### ampl_IEEOptTool_ELYRD.run:44(1896)   let ...
...
#execute	5e-06		0		21379488
### ./AMPL/IN/ampl_add_read_convdc.dat:34(2605)   read_table ...
#execute	0.013791	0		21379488
### ./AMPL/IN/ampl_add_read_rd.dat:7(288)   read_table ...
#execute	0.013838	48272		21427760
...
### ./AMPL/IN/ampl_add_read_tme_p.dat:6(375)   read_table ...
#compile	0.00013		0		31067192
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 144        1e-06        1e-06            0  filename_TME
## 145        5e-06        6e-06            0  filename_TME_gen
#genmod		1.5e-05		0		31067192
#execute	43.9226		6017579248	6048646440
### ./AMPL/IN/ampl_add_read_tme_p.dat:7(401)   read_table ...
#compile	0.000139	0		6048646440
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 146        2e-06        2e-06            0  filename_TME_lod
#genmod		1.2e-05		0		6048646440
#execute	47.6921		2404758000	8453404440
...
##seq      seconds    cum. sec.    mem. inc.  name
## 42        4e-06        4e-06            0  _ampl_time
## 45        3e-06        7e-06            0  _ampl_elapsed_time
## 111        2e-06        9e-06            0  p_timer
#genmod		1.9e-05		0		8592013352
#execute	3.3e-05		0		8592013352
### ampl_IEEOptTool_ELYRD.run:252(12731)   let ...
#compile	1.3e-05		0		8592013352
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 42        1e-06        1e-06            0  _ampl_time
## 45        3e-06        4e-06            0  _ampl_elapsed_time
#genmod		1.1e-05		0		8592013352
#execute	5e-06		0		8592013352
### ampl_IEEOptTool_ELYRD.run:253(12794)   printf ...
#compile	8e-06		0		8592013352
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 42        1e-06        1e-06            0  _ampl_time
## 45        2e-06        3e-06            0  _ampl_elapsed_time
#genmod		9e-06		0		8592013352
#execute	6e-06		0		8592013352
### ampl_IEEOptTool_ELYRD.run:257(13016)   printf ...
#execute	7e-06		0		8592013352
### ampl_IEEOptTool_ELYRD.run:259(13045)   let ...
#execute	6e-06		0		8592013352
### ampl_IEEOptTool_ELYRD.run:260(13080)   let ...
#execute	5e-06		0		8592013352
### ampl_IEEOptTool_ELYRD.run:261(13107)   let ...
#execute	2.2e-05		0		8592013352
### ampl_IEEOptTool_ELYRD.run:262(13174)   let ...
#compile	5e-06		0		8592013352
...
### ampl_IEEOptTool_ELYRD.run:266(13259)   let ...
#compile	5.1e-05		0		8592013352
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 107            0            0            0  DE
## 160        3e-06        3e-06            0  MPC_BUS_ID
## 162        2e-06        5e-06            0  MPC_GEN_ID
## 177      3.3e-05      3.8e-05            0  mpc_bus_zone
## 193      8.3e-05     0.000121            0  mpc_gen_bus
## 201      8.2e-05     0.000203            0  mpc_gen_pmax
## 270      8.3e-05     0.000286            0  add_gen_rd_category
## 451      4.6e-05     0.000332            0  MPC_BUS_ID_RD
#genmod		0.00034		0		8592013352
#execute	0.000143	0		8592013352
### ampl_IEEOptTool_ELYRD.run:275(13578)   if ...
### ampl_IEEOptTool_ELYRD.run:284(14014)   for ...
### ampl_IEEOptTool_ELYRD.run:285(14040)   if ...
...
### ampl_IEEOptTool_ELYRD.run:285(14040)   if ...
### ampl_IEEOptTool_ELYRD.run:287(14176)   if ...
### ampl_IEEOptTool_ELYRD.run:288(14209)   let ...
...
...
...
...
#execute	5e-06		0		8592078936
### ampl_IEEOptTool_ELYRD.run:285(14040)   if ...
...
### ampl_IEEOptTool_ELYRD.run:287(14176)   if ...
#execute	5e-06		0		8592078936
### ampl_IEEOptTool_ELYRD.run:285(14040)   if ...
### ampl_IEEOptTool_ELYRD.run:287(14176)   if ...
### ampl_IEEOptTool_ELYRD.run:288(14209)   let ...
...
#execute	4e-06		0		8592078936
### ampl_IEEOptTool_ELYRD.run:285(14040)   if ...
### ampl_IEEOptTool_ELYRD.run:287(14176)   if ...
### ampl_IEEOptTool_ELYRD.run:288(14209)   let ...
...
#genmod		1.2e-05		0		9532238320
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:11(531)   if ...
...
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:21(962)   for ...
#compile	0.000444	139704		9532378024
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 367        1e-06        1e-06            0  nblocks
## 371        3e-06        4e-06            0  TBLOCKS
#genmod		1.1e-05		0		9532378024
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:24(1042)   let ...
#compile	6e-06		0		9532378024
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 550            0            0            0  cb
#genmod		7e-06		0		9532378024
#execute	3e-06		0		9532378024
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:26(1184)   let ...
#compile	4.7e-05		0		9532378024
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 374      1.16896      1.16896            0  mpc_tme_gen_pg
## 380      2.6e-05      1.16899            0  ADD_RD_ID
## 382      1.3e-05        1.169            0  add_rd_type
## 448        9e-06      1.16901            0  ADD_RD_ID_STO
## 453     0.216762      1.38577            0  MPC_BUS_ID_STO_DE
## 553      5864.24      5865.63   3916890696  p_bus_sto_p
## 554     0.000107      5865.63            0  p_bus_sto_p_ch
#genmod		5865.63		3916890696	13449268720
#execute	8.16196		805972584	14255241304
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:31(1370)   let ...
#compile	5.4e-05		0		14255241304
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 555        2e-06        2e-06            0  p_bus_sto_p_dis
#genmod		1.2e-05		0		14255241304
#execute	8.16404		1070192624	15325433928
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:39(1679)   let ...
#compile	5.4e-05		0		15325433928
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 562      1.36824      1.36824            0  p_gen_sto_lvl_setpoint_TME
## 563      1.9e-05      1.36826            0  p_bus_sto_lvl_market
#genmod		1.36828		0		15325433928
#execute	1579.34		1199717816	16525151744
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:44(2021)   let ...
#compile	0.000115	0		16525151744
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
#genmod		1.55062		0		16525151744
#execute	0.168212	0		16525151744
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:50(2415)   let ...
#compile	3.7e-05		0		16525151744
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 272      1.3e-05      1.3e-05            0  add_gen_storage_level_max
## 274      1.5e-05      2.8e-05            0  add_gen_efficiency_pos
## 275      1.4e-05      4.2e-05            0  add_gen_efficiency_neg
## 557     0.630303     0.630345         4104  p_bus_sto_max
## 560     0.257164     0.887509            0  p_bus_sto_eff_pos
## 561     0.256946      1.14446            0  p_bus_sto_eff_neg
## 564      0.00024      1.14469            0  p_bus_sto_other_loss_p
#genmod		1.1447		4104		16525155848
#execute	11.0111		810518824	17335674672
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:58(2896)   option ...
#execute	5.3e-05		0		17335674672
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:61(3109)   if ...
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:65(3303)   if ...
### ./AMPL/LIB/ampl_ELYRD_TimeLoop.run:66(3368)   solve ...
#compile	0.000447	96800		17335771472
##genmod times:
##seq      seconds    cum. sec.    mem. inc.  name
## 89        1e-06        1e-06            0  derstage
## 93        3e-06        4e-06            0  sstatus
## 176      3.9e-05      4.3e-05            0  mpc_bus_base_kv
## 180      7.1e-05     0.000114            0  mpc_bra_f_bus
## 181      6.4e-05     0.000178            0  mpc_bra_t_bus
## 183      6.2e-05      0.00024            0  mpc_bra_x
## 185      6.3e-05     0.000303            0  mpc_bra_rate_a
## 190      6.1e-05     0.000364            0  mpc_bra_status
## 194        3e-06     0.000367            0  mpc_gen_pg
## 200      9.2e-05     0.000459            0  mpc_gen_status
## 202      8.7e-05     0.000546            0  mpc_gen_pmin
## 229        3e-06     0.000549            0  ADD_LOD_ID
...
## 773      1.10184      99613.3    962880096  =v_cost_rd_t
## 777     0.401736      99613.7    169929624  COST_RD
#genmod		99613.7		157896545520	175232316992
#merge		10.3014		8589934600	183822251592
#collect	45.2538		123689522472	307511774064
#presolve	218.497		130825061608	438336835672

Error at _cmdno 7524 executing "solve" command
(file ./AMPL/LIB/ampl_ELYRD_TimeLoop.run, line 66, offset 3368):

	Bug: dc0 botch in solve_out

The solve command’s presolve phase finishes successfully, so it appears that the bug is in the next phase of the solve command. The next phase is the output phase, which is consistent with the reference to solve_out in the error message.

I also see that when presolve finishes just before the error, AMPL has allocated 438,336,835,672 bytes of memory. This is very likely beyond the physical memory of the computer, requiring the use of slow virtual memory which may account for the runtime of over 24 hours.

We recommend looking at the complete “genmod times” output to see which model variables or constraints are taking the most memory to generate. Then study the model to determine why there are so many of those components, and whether it is possible to avoid generating a lot of them — as one example, there might be an excessive number of variables that are generated but are then set to zero or are never used.

Also, it may help to look at the times, gentimes, and show_stats statistics for one of the datasets that could be solved successfully. The model may be easier to study when working first with a dataset that generates a smaller problem.

Thank you very much for your reply. The model runs on a cluster with allocated memory of 1.5TB which is sufficient for this job.
I dont quite understand why the presolve phase is followed by a solver output. AMPL should first send the problem to gurobi to solve it. However, i dont see any Gurobi output (yes, output is switched on) in the output files.

I have already checked the gentimes output and indeed there are some variables and parameters that take excessive time to be computed. I will try to fix this. Nonetheless, this should not be the reason for the error message.