[Bug] Crash after creating a lot of replications

[jcace]

I created 50 replications with the POST /replications api and DDM crashed, is unable to start now with the following error message.

{"time":"2023-04-20T01:31:38.791180982-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"OPTIONS","uri":"/api/v1/health","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari
/537.36","status":204,"error":"","latency":39480,"latency_human":"39.48µs","bytes_in":0,"bytes_out":0}                                                                                                                                                                         
{"time":"2023-04-20T01:31:39.083666275-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"GET","uri":"/api/v1/health","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari/537
.36","status":200,"error":"","latency":93796378,"latency_human":"93.796378ms","bytes_in":0,"bytes_out":181}                                                                                                                                                                    
{"time":"2023-04-20T01:31:39.4754768-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"OPTIONS","uri":"/api/v1/datasets","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari
/537.36","status":204,"error":"","latency":38850,"latency_human":"38.85µs","bytes_in":0,"bytes_out":0}                                                                                                                                                                         
{"time":"2023-04-20T01:31:39.510239726-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"GET","uri":"/api/v1/health","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari/537
.36","status":200,"error":"","latency":207434120,"latency_human":"207.43412ms","bytes_in":0,"bytes_out":181}                                                                                                                                                                   
{"time":"2023-04-20T01:31:39.924634383-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"GET","uri":"/api/v1/datasets","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari/5
37.36","status":200,"error":"","latency":123549909,"latency_human":"123.549909ms","bytes_in":0,"bytes_out":1262}                                                                                                                                                               
{"time":"2023-04-20T01:31:40.107786366-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"OPTIONS","uri":"/api/v1/providers","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Saf
ari/537.36","status":204,"error":"","latency":10490,"latency_human":"10.49µs","bytes_in":0,"bytes_out":0}                                                                                                                                                                      
{"time":"2023-04-20T01:31:40.392133057-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"GET","uri":"/api/v1/providers","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safari/
537.36","status":200,"error":"","latency":45853917,"latency_human":"45.853917ms","bytes_in":0,"bytes_out":1129}                                                                                                                                                                
{"time":"2023-04-20T01:31:40.566200214-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"OPTIONS","uri":"/api/v1/replications","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 
Safari/537.36","status":204,"error":"","latency":8020,"latency_human":"8.02µs","bytes_in":0,"bytes_out":0}                                                                                                                                                                     
{"time":"2023-04-20T01:31:40.794576941-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"GET","uri":"/api/v1/replications","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safa
ri/537.36","status":200,"error":"","latency":56099554,"latency_human":"56.099554ms","bytes_in":0,"bytes_out":67417}                                                                                                                                                            
{"time":"2023-04-20T01:31:41.411196183-07:00","id":"","remote_ip":"10.32.32.1","host":"10.32.32.20:1314","method":"OPTIONS","uri":"/api/v1/wallets","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/112.0.0.0 Safar
i/537.36","status":204,"error":"","latency":10970,"latency_human":"10.97µs","bytes_in":0,"bytes_out":0}                                                                                                                                                                        
panic: runtime error: index out of range [0] with length 0                                                                                                                                                                                                                     
                                                                                                                                                                                                                                                                               
goroutine 18 [running]:                                                                                                                                                                                                                                                        
github.com/application-research/delta-dm/core.computeReplicationUpdates({0xc000780000?, 0x32, 0x0?})                                                                                                                                                                           
        /mnt/mnt_2/delta-standalone/delta-dm/core/delta-watcher.go:107 +0x4e5                                                                                                                                                                                                  
github.com/application-research/delta-dm/core.RunReconciliation(0x2540be400?, 0x0?)                                                                                                                                                                                            
        /mnt/mnt_2/delta-standalone/delta-dm/core/delta-watcher.go:63 +0x337                                                                                                                                                                                                   
github.com/application-research/delta-dm/core.watch(0x0?, 0x0?)                                                                                                                                                                                                                
        /mnt/mnt_2/delta-standalone/delta-dm/core/delta-watcher.go:36 +0x45                                                                                                                                                                                                    
created by github.com/application-research/delta-dm/core.(*DeltaDM).WatchReplications                                                                                                                                                                                          
        /mnt/mnt_2/delta-standalone/delta-dm/core/delta-watcher.go:29 +0x79 

[jcace]

This is caused because of content ID 272, the stats response from Delta looks like this:

[
	{
		"content": {
			"ID": 272,
			"name": "bafybeicp65k7lorewtgy3pwzihu42nbgren3fkbixiobn7u3qkehz7fagy",
			"size": 18259852128,
			"cid": "bafybeicp65k7lorewtgy3pwzihu42nbgren3fkbixiobn7u3qkehz7fagy",
			"requesting_api_key": "ESTc978971e-05a3-475b-ba13-7081317ddef6ARY",
			"piece_commitment_id": 264,
			"status": "deal-proposal-sent",
			"request_type": "",
			"connection_mode": "import",
			"auto_retry": false,
			"last_message": "",
			"created_at": "2023-04-20T01:24:49.056356252-07:00",
			"updated_at": "2023-04-20T01:25:20.857570787-07:00"
		},
		"deal_proposals": null,
		"deals": [
			{
				"ID": 257,
				"content": 272,
				"propCid": "bafyreidhvmw25ss3if3wv3s4vk7oeijp4u5swrut3u637tzjexgyxn2gzq",
				"dealUuid": "659a0d9b-79df-4895-8fc8-e1d109a995e2",
				"miner": "f01963614",
				"dealId": 0,
				"failed": false,
				"verified": true,
				"slashed": false,
				"failedAt": "0001-01-01T00:00:00Z",
				"dtChan": "",
				"transferStarted": "0001-01-01T00:00:00Z",
				"transferFinished": "0001-01-01T00:00:00Z",
				"onChainAt": "0001-01-01T00:00:00Z",
				"sealedAt": "0001-01-01T00:00:00Z",
				"lastMessage": "deal-proposal-sent",
				"deal_protocol_version": "/fil/storage/mk/1.2.0",
				"created_at": "2023-04-20T01:25:14.320848402-07:00",
				"updated_at": "2023-04-20T01:25:20.966850735-07:00"
			}
		],
		"piece_commitments": [
			{
				"ID": 264,
				"cid": "bafybeicp65k7lorewtgy3pwzihu42nbgren3fkbixiobn7u3qkehz7fagy",
				"piece": "baga6ea4seaqjecwhh6izfw724rkmqc4y57la6zfgg4fcwmsvoo7iuogdx5fvwia",
				"size": 18259852128,
				"padded_piece_size": 34359738368,
				"unnpadded_piece_size": 0,
				"status": "committed",
				"last_message": "",
				"created_at": "2023-04-20T01:24:48.948468667-07:00",
				"updated_at": "2023-04-20T01:25:20.749870253-07:00"
			}
		]
	}
]

The computeReconciliationUpdates func ( here ) is failing since it attempts to access deal.DealProposals[0] which is null

		case CONTENT_DEAL_PROPOSAL_SENT:
			toUpdate = append(toUpdate, Replication{
				Status:         StatusSuccess,
				ProposalCid:    deal.DealProposals[0].Signed,
				ContentCommP:   deal.PieceCommitments[0].Piece,
				DeltaContentID: deal.Content.ID,
				DeltaMessage:   deal.Content.LastMessage,
			})

@alvin-reyes I haven't seen this happen before. It looks like the deal was successful but for some reason delta left dealProposals null. Is there a better way we should check it on the DDM side?

[jcace]

The deal itself looks fine to me

[alvin-reyes]

Use deal.propCid instead. This is a property of the deal.

"propCid": "bafyreidhvmw25ss3if3wv3s4vk7oeijp4u5swrut3u637tzjexgyxn2gzq"

I think its better to have a fail safe checks for the arrays.

if len(deal.DealProposals) < 1 {
   // set field to an empty ""
}
if len(deal.PieceCommitments) < 1 {
   // set field to an empty ""
}