VertexFitter gives a lot of errors

matthewkenzie commented 4 months ago

I have noticed that Vertex Fitting spits out a huge number of error messages (seemingly related to the covariance matrix of the vertex fit).

This can be directly reproduced by running the vertex fitting tutorial (but also applies to my own specific analysis attempts):

cd FCCAnalyses/examples/FCCee/tutorials/vertexing
fccanalysis run analysis_primary_vertex.py --test

I believe the error message occurs for EVERY event and is somehow related to VertexMore (when it tries to fill the covariance matrix). I also notice that there are occasional errors coming from TrkUtil.

What is irritating about these errors is that they stem from delphes not from the FCCAnalyses code itself so cannot be fixed by making local changes.

Does anyone have any recommendations of how best to proceed?

AidanWiederhold commented 4 months ago

This issue is relevant for a number of flavour studies, for now code can be set up assuming this isn't an issue but it would be nice to resolve ASAP in case things need to be rerun.

kjvbrt commented 4 months ago

Hi @matthewkenzie, @AidanWiederhold, we were discussing this yesterday at the meeting with @selvaggi. I'm not sure how severe this error messages are, but in order to suppress them I prepared this ugly PR #379. The PR is for the pre-edm4hep1 branch which contains bug fixes for the 0.9.0 version of the FCCAnalyses.

matthewkenzie commented 4 months ago

Thanks @kjvbrt that does indeed help to suppress the messages. The vertex information we get still comes out sensible but I suspect that if the covariance matrix of the vertex fit is required it will not be available (or filled with junk).

AidanWiederhold commented 2 months ago

@kjvbrt thanks for adding the suppression, it certainly makes the logs more sensible sizes! However I think there must be some underlying issue, at the very least tupling that in the past would've taken on the order of a few minutes for about 20 input files now takes over an hour for a single file. This makes doing any kind of development of the candidate building extremely slow. Ideally I want to run a Master's project using this in a month or so but I don't see how I'll be able to do this if the students have to use their limited time working on this waiting for even simple tests to finish.

Even a simple script where the analyzers function is just doing

df3 = (df
               #############################################
               ##          Aliases for # in python        ##
               #############################################
               .Alias("MCRecoAssociations0", "MCRecoAssociations#0.index")
               .Alias("MCRecoAssociations1", "MCRecoAssociations#1.index")
               .Alias("Particle0", "Particle#0.index")
               .Alias("Particle1", "Particle#1.index")

               #############################################
               ##MC record to study the Z->bb events types##
               #############################################               
               .Define("MC_PDG", "FCCAnalyses::MCParticle::get_pdg(Particle)")
               .Define("MC_n",   "int(MC_PDG.size())")
               .Define("MC_M1",  "FCCAnalyses::myUtils::getMC_parent(0,Particle,Particle0)")
               .Define("MC_M2",  "FCCAnalyses::myUtils::getMC_parent(1,Particle,Particle0)")
               .Define("MC_D1",  "FCCAnalyses::myUtils::getMC_daughter(0,Particle,Particle1)")
               .Define("MC_D2",  "FCCAnalyses::myUtils::getMC_daughter(1,Particle,Particle1)")
               .Define("MC_D3",  "FCCAnalyses::myUtils::getMC_daughter(2,Particle,Particle1)")
               .Define("MC_D4",  "FCCAnalyses::myUtils::getMC_daughter(3,Particle,Particle1)")
               .Define("MC_orivtx_x",   "FCCAnalyses::MCParticle::get_vertex_x(Particle)")
               .Define("MC_orivtx_y",   "FCCAnalyses::MCParticle::get_vertex_y(Particle)")
               .Define("MC_orivtx_z",   "FCCAnalyses::MCParticle::get_vertex_z(Particle)")
               .Define("MC_endvtx_x",   "FCCAnalyses::MCParticle::get_endPoint_x(Particle)")
               .Define("MC_endvtx_y",   "FCCAnalyses::MCParticle::get_endPoint_y(Particle)")
               .Define("MC_endvtx_z",   "FCCAnalyses::MCParticle::get_endPoint_z(Particle)")
               .Define("MC_p",   "FCCAnalyses::MCParticle::get_p(Particle)")
               .Define("MC_pt",  "FCCAnalyses::MCParticle::get_pt(Particle)")
               .Define("MC_px",  "FCCAnalyses::MCParticle::get_px(Particle)")
               .Define("MC_py",  "FCCAnalyses::MCParticle::get_py(Particle)")
               .Define("MC_pz",  "FCCAnalyses::MCParticle::get_pz(Particle)")
               .Define("MC_e",   "FCCAnalyses::MCParticle::get_e(Particle)")
               .Define("MC_m",   "FCCAnalyses::MCParticle::get_mass(Particle)")
               .Define("MC_q",   "FCCAnalyses::MCParticle::get_charge(Particle)")
               .Define("MC_eta", "FCCAnalyses::MCParticle::get_eta(Particle)")
               .Define("MC_phi", "FCCAnalyses::MCParticle::get_phi(Particle)")

               #############################################
               ##               Build MC Vertex           ##
               #############################################
               .Define("MCVertexObject", "FCCAnalyses::myUtils::get_MCVertexObject(Particle, Particle0)")
               .Define("MC_Vertex_x",    "FCCAnalyses::myUtils::get_MCVertex_x(MCVertexObject)")
               .Define("MC_Vertex_y",    "FCCAnalyses::myUtils::get_MCVertex_y(MCVertexObject)")
               .Define("MC_Vertex_z",    "FCCAnalyses::myUtils::get_MCVertex_z(MCVertexObject)")
               .Define("MC_Vertex_ind",  "FCCAnalyses::myUtils::get_MCindMCVertex(MCVertexObject)")
               .Define("MC_Vertex_ntrk", "FCCAnalyses::myUtils::get_NTracksMCVertex(MCVertexObject)")
               .Define("MC_Vertex_n",    "int(MC_Vertex_x.size())")
               .Define("MC_Vertex_PDG",  "FCCAnalyses::myUtils::get_MCpdgMCVertex(MCVertexObject, Particle)")
               .Define("MC_Vertex_PDGmother",  "FCCAnalyses::myUtils::get_MCpdgMotherMCVertex(MCVertexObject, Particle)")
               .Define("MC_Vertex_PDGgmother", "FCCAnalyses::myUtils::get_MCpdgGMotherMCVertex(MCVertexObject, Particle)")
        )

        df4 = (df3

               #############################################
               ##              Build Reco Vertex          ##
               #############################################
                .Define("VertexObject", "FCCAnalyses::myUtils::get_VertexObject(MCVertexObject,ReconstructedParticles,EFlowTrack_1,MCRecoAssociations0,MCRecoAssociations1)")

            #    #############################################
            #    ##          Build PV var and filter        ##
            #    #############################################
                .Define("EVT_hasPV",    "FCCAnalyses::myUtils::hasPV(VertexObject)")
               .Filter("EVT_hasPV==1")

Is enough to reproduce this, if you comment out the bits that rely on vertexing it can finish in under a minute for a single input file, if you don't then it takes far longer.

AidanWiederhold commented 2 months ago

For context here's the log of a condor job that just finished showing how long it took. I also wonder if that error message is relevant

----> INFO: Loading analyzers from libFCCAnalyses...
----> INFO: Loading analysis file:
            /afs/cern.ch/work/a/aiwieder/private/FCC/FCCAnalyses/examples/FCCee/flavour/b2snunu/scripts/stage1_nonSM.py
----> INFO: No multithreading enabled. Running in single thread...
----> INFO: Running over files provided in command line argument...
----> INFO: Creating dataframe object from files:
            - root://eospublic.cern.ch//eos/experiment/fcc/ee/generation/DelphesEvents/winter2023/IDEA/p8_ee_Zbb_ecm91_EvtGen_Bd2KstNuNu/events_135162294.root  

----> INFO: Number of local events: 100,000
----> INFO: Output file path:
            /eos/experiment/fcc/ee/analyses_storage/flavor/b2snunu/revival/stage1/p8_ee_Zbb_ecm91_EvtGen_Bd2KstNuNu/chunk_3.root
Error in <Minuit2>: VariableMetricBuilder Initial matrix not pos.def.
----> INFO: =================================== SUMMARY ====================================
            Elapsed time (H:M:S):    02:26:07
            Events processed/second: 11
            Total events processed:  100,000
            No. result events:       89,440
            Reduction factor local:  0.8944
            ================================================================================

HEP-FCC / FCCAnalyses

VertexFitter gives a lot of errors #378