Input file "is not writable" error when reading a skimmed NTuple

abrinke1 · May 31, 2019, 3:44pm

Hi all,

I encounter a very strange error when trying to read an NTuple that I produced by skimming. The code to perform the skim is here:

github.com

abrinke1/cmssw/blob/AWB_displaced_dev_v1_macros/L1Trigger/L1TNtuples/macros/SkimNTuples.py

#! /usr/bin/env python

## Skim NTuples based on nPV or other properties

import sys
import subprocess
import ROOT as R

def main():

    print '\nInside SkimNTuples\n'

    IDX = 0

    PRT_EVT  =       1000  ## Print every Nth event
    MAX_EVT  =    1000000  ## Number of events to process
    MIN_FILE =     IDX*2  ## Minimum input file index to process
    MAX_FILE = (IDX+1)*2  ## Maximum input file index to process
    MIN_PU = 50         ## Only save events with PU > XX

This file has been truncated. show original

I use CloneTree(0) to create a new tree, fill it with Fill() for selected events, and out_file.Write() to write the output. I can open the output file and make plots clicking through the TBrowser without any issues.

However, when I use another python script to read the skimmed output file:

github.com

abrinke1/cmssw/blob/AWB_displaced_dev_v1_macros/L1Trigger/L1TNtuples/macros/ETT_rate.py

#! /usr/bin/env python

## Look at rate of VBF seeds in ZeroBias data

import sys

from ROOT import *
gROOT.SetBatch(False)
import math
# from Helper import *
import subprocess

def main():

    print 'Inside ETT_rate'

    PRT_EVT  =   1  ## Print every Nth event
    MAX_EVT  = 100  ## Number of events to process
    MAX_FILE =   1  ## Number of files to process
    # GOOD_RUNS = [306041, 306037, 306121]

This file has been truncated. show original

I get the following error message:
Error in TDirectoryFile::WriteObject: File /eos/cms/store/group/dpg_trigger/comm_trigger/L1Trigger/bundocka/ZeroBias/zbMETe/L1Ntuple_Skim_PU50_0.root is not writable
Fatal in : Not yet implemented, require copy of objects.

The file mentioned is the input file, i.e. the skim file that I created. I’m not trying to write it, and I don’t know what this “Insert” function is. The odd thing is that this script runs just fine over the original files that were used to make the skimmed file.

I’m happy to provide more details or run tests: let me know if you have any ideas!

Thanks much,
Andrew

ROOT Version: 6.12/07
Platform: Python 2.7.14+
Compiler: Not Provided

StephanH · June 3, 2019, 10:32am

Hi Andrew,

I invite @Axel and @pcanal to have a look.

Axel · June 4, 2019, 6:46am

I see nothing obvious. You could add some print statements to bisect where these errors are coming from.

abrinke1 · June 4, 2019, 9:29am

Hi @Axel,
Thanks for taking a look. I added the printouts, and the error occurs when I first call “GetEntries”:

github.com

abrinke1/cmssw/blob/AWB_displaced_dev_v1_macros/L1Trigger/L1TNtuples/macros/ETT_rate.py#L154


# Emu_br = L1Analysis.L1AnalysisL1UpgradeDataFormat()


print '\nSetting vertex branch address'
# chains['Evt'].SetBranchAddress('Event',     AddressOf(Evt_br))
chains['Vtx'].SetBranchAddress('Vertex',    AddressOf(Vtx_br))
# chains['Unp'].SetBranchAddress('L1Upgrade', AddressOf(Unp_br))
# chains['Emu'].SetBranchAddress('L1Upgrade', AddressOf(Emu_br))




print '\nEntering loop over events:'
print chains['Vtx'].GetEntries()
for iEvt in range(chains['Vtx'].GetEntries()):


    print '\nAbout to get entry #%d for l1RecoTree/RecoTree tree' % iEvt
    # chains['Evt'].GetEntry(iEvt)
    chains['Vtx'].GetEntry(iEvt)


    # ## Do this if you don't explicitly define the DataFormat and do SetBranchAddress above
    # Evt_br = chains['Evt'].Event
    # Vtx_br = chains['Vtx'].Vertex
    # Unp_br = chains['Unp'].L1Upgrade

What I’m particularly confused about is how or why a “GetEntries” is interpreted as trying to write to the file. Here is the error message in full:

[abrinke1@lxplus627 L1TNtuples]$ ./macros/ETT_rate.py
Inside ETT_rate
Adding file /eos/cms/store/group/dpg_trigger/comm_trigger/L1Trigger/bundocka/ZeroBias/zbMETe/L1Ntuple_Skim_PU50_0.root

Defining vertex branch as L1AnalysisRecoVertexDataFormat

Setting vertex branch address

Entering loop over events:
Error in <TDirectoryFile::WriteObject>: File /eos/cms/store/group/dpg_trigger/comm_trigger/L1Trigger/bundocka/ZeroBias/zbMETe/L1Ntuple_Skim_PU50_0.root is not writable
Fatal in <Insert>: Not yet implemented, require copy of objects.
aborting

Thread 2 (Thread 0x7fc94f8b3700 (LWP 30107)):
#0  0x00007fc96442ba00 in sem_wait () from /lib64/libpthread.so.0
#1  0x00007fc964783898 in PyThread_acquire_lock (lock=lock
entry=0x13d2d60, waitflag=waitflag
entry=1) at Python/thread_pthread.h:324
#2  0x00007fc96473fec6 in PyEval_RestoreThread (tstate=tstate
entry=0x3a545b0) at Python/ceval.c:359
#3  0x00007fc964964be4 in floatsleep (secs=<optimized out>) at /build/cmsbld/auto-builds/CMSSW_10_1_0-slc6_amd64_gcc700/build/CMSSW_10_1_0-build/BUILD/slc6_amd64_gcc700/external/python/2.7.14-omkpbe4/python-2.7.14/Modules/timemodule.c:1057
#4  time_sleep (self=<optimized out>, args=<optimized out>) at /build/cmsbld/auto-builds/CMSSW_10_1_0-slc6_amd64_gcc700/build/CMSSW_10_1_0-build/BUILD/slc6_amd64_gcc700/external/python/2.7.14-omkpbe4/python-2.7.14/Modules/timemodule.c:206
#5  0x00007fc964749a96 in call_function (oparg=<optimized out>, pp_stack=0x7fc94f8b2570) at Python/ceval.c:4357
#6  PyEval_EvalFrameEx (f=f
entry=0x7fc94f8d6050, throwflag=throwflag
entry=0) at Python/ceval.c:2994
#7  0x00007fc96474a7a8 in PyEval_EvalCodeEx (co=<optimized out>, globals=<optimized out>, locals=locals
entry=0x0, args=args
entry=0x7fc94f8d8b28, argcount=<optimized out>, kws=kws
entry=0x7fc964a03068, kwcount=0, defs=0x0, defcount=0, closure=0x0) at Python/ceval.c:3589
#8  0x00007fc9646c0bad in function_call (func=0x7fc94fdf6500, arg=0x7fc94f8d8b10, kw=0x7fc94fe486e0) at Objects/funcobject.c:523
#9  0x00007fc964690ef3 in PyObject_Call (func=func
entry=0x7fc94fdf6500, arg=arg
entry=0x7fc94f8d8b10, kw=kw
entry=0x7fc94fe486e0) at Objects/abstract.c:2547
#10 0x00007fc9647430b9 in ext_do_call (nk=<optimized out>, na=0, flags=<optimized out>, pp_stack=0x7fc94f8b27e8, func=0x7fc94fdf6500) at Python/ceval.c:4671
#11 PyEval_EvalFrameEx (f=f
entry=0x7fc95dab8b00, throwflag=throwflag
entry=0) at Python/ceval.c:3033
#12 0x00007fc964749077 in fast_function (nk=<optimized out>, na=<optimized out>, n=1, pp_stack=0x7fc94f8b28f0, func=<optimized out>) at Python/ceval.c:4442
#13 call_function (oparg=<optimized out>, pp_stack=0x7fc94f8b28f0) at Python/ceval.c:4377
#14 PyEval_EvalFrameEx (f=f
entry=0x7fc948000910, throwflag=throwflag
entry=0) at Python/ceval.c:2994
#15 0x00007fc964749077 in fast_function (nk=<optimized out>, na=<optimized out>, n=1, pp_stack=0x7fc94f8b2a00, func=<optimized out>) at Python/ceval.c:4442
#16 call_function (oparg=<optimized out>, pp_stack=0x7fc94f8b2a00) at Python/ceval.c:4377
#17 PyEval_EvalFrameEx (f=f
entry=0x7fc95dae6c90, throwflag=throwflag
entry=0) at Python/ceval.c:2994
#18 0x00007fc96474a7a8 in PyEval_EvalCodeEx (co=<optimized out>, globals=<optimized out>, locals=locals
entry=0x0, args=args
entry=0x7fc94fe07d68, argcount=<optimized out>, kws=kws
entry=0x0, kwcount=0, defs=0x0, defcount=0, closure=0x0) at Python/ceval.c:3589
#19 0x00007fc9646c0ad9 in function_call (func=0x7fc94f8ba7d0, arg=0x7fc94fe07d50, kw=0x0) at Objects/funcobject.c:523
#20 0x00007fc964690ef3 in PyObject_Call (func=func
entry=0x7fc94f8ba7d0, arg=arg
entry=0x7fc94fe07d50, kw=kw
entry=0x0) at Objects/abstract.c:2547
#21 0x00007fc96469fc8c in instancemethod_call (func=0x7fc94f8ba7d0, arg=0x7fc94fe07d50, kw=0x0) at Objects/classobject.c:2600
#22 0x00007fc964690ef3 in PyObject_Call (func=func
entry=0x7fc95daadaa0, arg=arg
entry=0x7fc964a03050, kw=<optimized out>) at Objects/abstract.c:2547
#23 0x00007fc964740577 in PyEval_CallObjectWithKeywords (func=0x7fc95daadaa0, arg=0x7fc964a03050, kw=<optimized out>) at Python/ceval.c:4226
#24 0x00007fc964789a22 in t_bootstrap (boot_raw=0x3a46f80) at ./Modules/threadmodule.c:620
#25 0x00007fc964425aa1 in start_thread () from /lib64/libpthread.so.0
#26 0x00007fc963ae7c4d in clone () from /lib64/libc.so.6

Thread 1 (Thread 0x7fc964a44700 (LWP 29948)):
#0  0x00007fc963aab8dd in waitpid () from /lib64/libc.so.6
#1  0x00007fc963a3d4e9 in do_system () from /lib64/libc.so.6
#2  0x00007fc963a3d820 in system () from /lib64/libc.so.6
#3  0x00007fc95d19fb21 in TUnixSystem::StackTrace() () from /cvmfs/cms.cern.ch/slc6_amd64_gcc700/cms/cmssw/CMSSW_10_3_1/external/slc6_amd64_gcc700/lib/libCore.so
#4  0x00007fc95d095120 in DefaultErrorHandler(int, bool, char const*, char const*) () from /cvmfs/cms.cern.ch/slc6_amd64_gcc700/cms/cmssw/CMSSW_10_3_1/external/slc6_amd64_gcc700/lib/libCore.so
#5  0x00007fc95d094b92 in ErrorHandler () from /cvmfs/cms.cern.ch/slc6_amd64_gcc700/cms/cmssw/CMSSW_10_3_1/external/slc6_amd64_gcc700/lib/libCore.so
#6  0x00007fc95d094fd2 in Fatal(char const*, char const*, ...) () from /cvmfs/cms.cern.ch/slc6_amd64_gcc700/cms/cmssw/CMSSW_10_3_1/external/slc6_amd64_gcc700/lib/libCore.so
#7  0x00007fc95d761fe3 in TChain::LoadTree(long long) () from /cvmfs/cms.cern.ch/slc6_amd64_gcc700/cms/cmssw/CMSSW_10_3_1/external/slc6_amd64_gcc700/lib/libTree.so
#8  0x00007fc95d75f7ee in TChain::GetEntries() const () from /cvmfs/cms.cern.ch/slc6_amd64_gcc700/cms/cmssw/CMSSW_10_3_1/external/slc6_amd64_gcc700/lib/libTree.so
#9  0x00007fc957602039 in ?? ()
#10 0x000000000a7643e0 in ?? ()
#11 0x00007ffd28799de8 in ?? ()
#12 0x00007ffd28799de8 in ?? ()
#13 0x00007ffd28799d20 in ?? ()
#14 0x0000000003c1a4d0 in ?? ()
#15 0x0000000003c8be70 in ?? ()
#16 0x00007ffd28799dd0 in ?? ()
#17 0x00007fc95da4a7eb in FastCall(long, void*, void*, void*) () from /cvmfs/cms.cern.ch/slc6_amd64_gcc700/lcg/root/6.12.07-ogkkac4/lib/libPyROOT.so
Abort (core dumped)

Thanks again for any ideas you might have.

Best regards,
Andrew

pcanal · June 5, 2019, 8:09pm

This message comes from TEmulatedCollectionProxy::Insert but the stack trace claims it comes from TChain::LoadTree

Consequently I suspect a memory corruption somewhere. Can you run the failing example with valgrind?

Axel · June 7, 2019, 7:42am

That’s valgrind --suppressions=$ROOTSYS/etc/valgrind-root-python.supp --suppressions=$ROOTSYS/etc/valgrind-root.supp python ./macros/ETT_rate.py

abrinke1 · June 7, 2019, 10:46am

Hi @Axel, thanks a bunch! I had spent a bit of time fruitlessly trying other methods to get valgrind to give proper output combined with python …

I’ve attached the valgrind output. Hopefully it means more to you than it does to me. I see a lot of “Conditional jump or move depends on uninitialised value(s)” which I suspect are irrelevant. Otherwise nothing I can make heads or tails of: I’ve included a “slim” version as well with just the errors immediately around the segfault.

Thanks much,
Andrew

ETT_rate_valgrind.txt (234.0 KB)

ETT_rate_valgrind_slim.txt (8.1 KB)

Axel · June 7, 2019, 1:34pm

That’s bad - @pcanal check the full log starting at Defining vertex branch as L1AnalysisRecoVertexDataFormat.

pcanal · June 7, 2019, 8:13pm

Indeed it indicates a problem but we do not have enough information yet.

@abrinke1 could you rerun valgrind with the extra parameters: --track-origins==yes --num-callers=50 and/or provide a running reproducer?

Thanks,
Philippe.

abrinke1 · June 10, 2019, 9:18am

Hi @pcanal,
I’ve attached the fuller output as you requested.
Best,
Andrew

ETT_rate_valgrind_v2.txt (867.1 KB)

pcanal · June 10, 2019, 11:14pm

WIth the new detailed, it looks like those errors are (very likely) false positive that we prevented valgrind to complain about only in v6.18. Could you try with the ‘master’ of ROOT (as v6.18 has not been released yet).

Thanks,
Philippe.

system · June 24, 2019, 11:15pm

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.