Many (>400!) failed migrations in last days

[belforte]

Indeed I am not sure if there is a bug, or if some service is down or in bad status and the bug is the lack of monitoring, or problems in communications among services... Feel free to re-label

Impact of the bug
CRAB Publisher. Tons of failed publications and ~700 files stuck in waiting to be published.

Describe the bug
see issue title

How to reproduce it
delete on of the listed migrations and create it again

Expected behavior
migrations should always work !

[belforte]

Hi. Starting Aug 23 we have got a very large numbers of terminally failed migration (state = 9) from prod/global to prod/phys03
I tried to delete and re-created a few of them, but still got 9 within a few minutes (
Can you please investigate ? They pertain to different datasets.

Here are some most recent migrations IDs:

5545800
5545801
5545804
5545805
5545806
5545808
5545809
5545810
5545813
5545814
5545815
5545817
5545818
5545819
5545822
5545823
5545824
5545825
5545827

Let me know if you need other information, but ID is sufficient to tell which block was being migrated and possibly retry.
I use code in here to try delete/recreate

[belforte]

I can't find those migration ID in DBS anymore, is there some new thing where id's are removed ?
Anyhow here's one which failed today (state=9)

migrationId: 5547494 was created on 2025-08-29 13:26:43 by /DC=ch/DC=cern/OU=Organic Units/OU=Users/CN=cmscrab/CN=373708/CN=Robot: cms crab for block:
 /WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/RunIISummer20UL16MiniAODAPVv2-106X_mcRun2_asymptotic_preVFP_v11-v3/MINIAODSIM#9df2f147-f966-4b78-b4cf-0ca76e1dba08

full details below in [1]

I tried to look at logs and I am confused since this ID appears both in the log for the migration server indicated in [1]

• dbs2go-phys03-migration-58497c5b5d-wszjz.log-20250829 [2]
  and in another log
• dbs2go-phys03-migration-6464bbb4b6-v99r4.log-20250829 [3]

(both files are on vocms0755 in /cephfs/product/dbs-logs

In log [2] I find

[2025-08-29 11:26:50.612359271 +0000 UTC m=+273376.041561645] migrate.go:1116: insert bulkblocks for mid 5547494 error DBSError Code:101 Description:DBS DB error Function:dbs.bulkblocks.InsertBulkBlocksConcurrently Message:unable to find parent lfn /store/mc/RunIISummer20UL16RECOAPV/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/AODSIM/106X_mcRun2_asymptotic_preVFP_v8-v3/2520001/EB2A7499-44A0-B74F-BBC9-C85E32A703C8.root Error: nested DBSError Code:103 Description:DBS DB query error, e.g. mailformed SQL statement Function:dbs.GetID Message: Error: sql: no rows in result set
[2025-08-29 11:26:50.61309617 +0000 UTC m=+273376.042298553] migrate.go:1119: insert block dump record failed with DBSError Code:101 Description:DBS DB error Function:dbs.bulkblocks.InsertBulkBlocksConcurrently Message:unable to find parent lfn /store/mc/RunIISummer20UL16RECOAPV/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/AODSIM/106X_mcRun2_asymptotic_preVFP_v8-v3/2520001/EB2A7499-44A0-B74F-BBC9-C85E32A703C8.root Error: nested DBSError Code:103 Description:DBS DB query error, e.g. mailformed SQL statement Function:dbs.GetID Message: Error: sql: no rows in result set
[2025-08-29 11:26:50.613634309 +0000 UTC m=+273376.042836682] migrate.go:1378: update migration request 5547494 to status 3

repeated 3 times

While in the log [3] there is the same message, again repeated 3 times

[2025-08-29 11:26:51.714977435 +0000 UTC m=+273802.210940220] migrate.go:1116: insert bulkblocks for mid 5547494 error DBSError Code:101 Description:DBS DB error Function:dbs.bulkblocks.InsertBulkBlocksConcurrently Message:unable to find parent lfn /store/mc/RunIISummer20UL16RECOAPV/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/AODSIM/106X_mcRun2_asymptotic_preVFP_v8-v3/2520001/EB2A7499-44A0-B74F-BBC9-C85E32A703C8.root Error: nested DBSError Code:103 Description:DBS DB query error, e.g. mailformed SQL statement Function:dbs.GetID Message: Error: sql: no rows in result set
[2025-08-29 11:26:51.715582188 +0000 UTC m=+273802.211544973] migrate.go:1119: insert block dump record failed with DBSError Code:101 Description:DBS DB error Function:dbs.bulkblocks.InsertBulkBlocksConcurrently Message:unable to find parent lfn /store/mc/RunIISummer20UL16RECOAPV/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/AODSIM/106X_mcRun2_asymptotic_preVFP_v8-v3/2520001/EB2A7499-44A0-B74F-BBC9-C85E32A703C8.root Error: nested DBSError Code:103 Description:DBS DB query error, e.g. mailformed SQL statement Function:dbs.GetID Message: Error: sql: no rows in result set
[2025-08-29 11:26:51.715840161 +0000 UTC m=+273802.211802946] migrate.go:1378: update migration request 5547494 to status 3

repeated a few times.

As to the unable to find parent lfn /store/mc/RunIISummer20UL16RECOAPV/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/AODSIM/106X_mcRun2_asymptotic_preVFP_v8-v3/2520001/EB2A7499-44A0-B74F-BBC9-C85E32A703C8.root

That LFN is happily present in the global instance, from where it should be migrated to phys03

show

```text dasgoclient --query 'file file=/store/mc/RunIISummer20UL16RECOAPV/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/AODSIM/106X_mcRun2_asymptotic_preVFP_v8-v3/2520001/EB2A7499-44A0-B74F-BBC9-C85E32A703C8.root' --json|jq [ { "das": { "expire": 1756469659, "instance": "prod/global", "primary_key": "file.name", "record": 1, "services": [ "dbs3:files" ] }, "file": [ { "adler32": "7728b751", "auto_cross_section": 0, "block.name": "/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/RunIISummer20UL16RECOAPV-106X_mcRun2_asymptotic_preVFP_v8-v3/AODSIM#06abb801-e30f-42a0-ae07-3ecffe4b47fe", "block_id": 39258181, "block_name": "/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/RunIISummer20UL16RECOAPV-106X_mcRun2_asymptotic_preVFP_v8-v3/AODSIM#06abb801-e30f-42a0-ae07-3ecffe4b47fe", "branch_hash_id": null, "check_sum": "22019679", "create_by": "WMAgent", "created_by": "WMAgent", "creation_date": 1734754319, "creation_time": 1734754319, "dataset": "/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/RunIISummer20UL16RECOAPV-106X_mcRun2_asymptotic_preVFP_v8-v3/AODSIM", "dataset_id": 15201936, "file_id": 18841361917, "file_type_id": 1, "is_file_valid": 1, "last_modification_date": 1734754319, "last_modified_by": "WMAgent", "md5": null, "modification_time": 1734754319, "modified_by": "WMAgent", "name": "/store/mc/RunIISummer20UL16RECOAPV/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/AODSIM/106X_mcRun2_asymptotic_preVFP_v8-v3/2520001/EB2A7499-44A0-B74F-BBC9-C85E32A703C8.root", "nevents": 10120, "size": 2587931383, "type": "EDM" } ], "qhash": "a9fc3b6b91f1c6be7ef95fc44a0ae615" } ] ```

Looks to me like

1. two migration servers are acting on same migration at ~same time, which I doubt is intentional
2. the migration server should migrate parents first, target block later, we already went throught this back at the time of initial commissioning and functionality should be there. But somehow it seems that at times this is skipped.

I suggest that you try to migrate this yourself and step through the code to debug it.
I do not think that there is anything more that I can do.

[1]

{'create_by': '/DC=ch/DC=cern/OU=Organic '
              'Units/OU=Users/CN=cmscrab/CN=373708/CN=Robot: cms crab',
 'creation_date': 1756466803,
 'last_modification_date': 1756466803,
 'last_modified_by': '/DC=ch/DC=cern/OU=Organic '
                     'Units/OU=Users/CN=cmscrab/CN=373708/CN=Robot: cms crab',
 'migration_input': '/WtoNMu_MN-5_V-0p00001_TuneCP5_13TeV_madgraph-pythia8/RunIISummer20UL16MiniAODAPVv2-106X_mcRun2_asymptotic_preVFP_v11-v3/MINIAODSIM#9df2f147-f966-4b78-b4cf-0ca76e1dba08',
 'migration_request_id': 5547494,
 'migration_server': 'dbs2go-phys03-migration-58497c5b5d-wszjz',
 'migration_status': 9,
 'migration_url': 'https://cmsweb-prod.cern.ch:8443/dbs/prod/global/DBSReader',
 'retry_count': 4}

[belforte]

ref: #80

[belforte]

looks the same as #115 which somehow happened again, with vengeance !

[belforte]

@todor-ivanov ping problem is still there

[belforte]

here's a very recent example:

"{'create_by': '/DC=ch/DC=cern/OU=Organic "
 "Units/OU=Users/CN=cmscrab/CN=373708/CN=Robot: cms crab', 'creation_date': "
 "1757529415, 'last_modification_date': 1757529415, 'last_modified_by': "
 "'/DC=ch/DC=cern/OU=Organic Units/OU=Users/CN=cmscrab/CN=373708/CN=Robot: cms "
 "crab', 'migration_input': "
 "'/WZtoLNu2Q_TuneCP5_13p6TeV_powheg-pythia8/RunIII2024Summer24MiniAOD-140X_mcRun3_2024_realistic_v26-v2/MINIAODSIM#31b208d0-bc84-4009-97fc-2de8c1895d04', "
 "'migration_request_id': 5622300, 'migration_server': "
 "'dbs2go-phys03-migration-58497c5b5d-wszjz', 'migration_status': 9, "
 "'migration_url': "
 "'https://cmsweb-prod.cern.ch:8443/dbs/prod/global/DBSReader', 'retry_count': "
 '4}')

do we have to give up on DBS migrations ? @anpicci @amaltaro

[todor-ivanov]

hi @belforte

do we have to give up on DBS migrations ?

No.

I am looking into it now.

[belforte]

today we @todor-ivanov and myself had a long debugging session.
AFAIU the root cause is that some block got migrated in Phys03 w/o the files. This leads to CRAB asking for it to be migrated again (parent files must be present in Phys03 for publication of new datasets) and this request fails because DBS has no way to fix the broken block.
Here's an example from one of the blocks which are persistently failing to migrate in CRAB Publisher:

belforte@lxplus813/~> dasgoclient --query 'file block=/BToPhi_MPhi-0p7_ctau-10mm_TuneCP5_13p6TeV_pythia8/Run3Summer22DRPremix-124X_mcRun3_2022_realistic_v12-v2/AODSIM#95a97811-3258-44aa-a400-1fd406bf5d7b instance=prod/global'
/store/mc/Run3Summer22DRPremix/BToPhi_MPhi-0p7_ctau-10mm_TuneCP5_13p6TeV_pythia8/AODSIM/124X_mcRun3_2022_realistic_v12-v2/70000/aa1bb70c-6b2e-4202-97b1-c84eb77ebb97.root
belforte@lxplus813/~> dasgoclient --query 'file block=/BToPhi_MPhi-0p7_ctau-10mm_TuneCP5_13p6TeV_pythia8/Run3Summer22DRPremix-124X_mcRun3_2022_realistic_v12-v2/AODSIM#95a97811-3258-44aa-a400-1fd406bf5d7b instance=prod/phys03'
belforte@lxplus813/~>