Jobsub ID 235688.1@dunegpschedd02.fnal.gov
| Jobsub ID | 235688.1@dunegpschedd02.fnal.gov |
| Workflow ID | 9405 |
| Stage ID | 1 |
| User name | ykermaid@fnal.gov |
| HTCondor Group | group_dune.prod_mcsim |
| Requested | Processors | 1 |
| GPU | No |
| RSS bytes | 4193255424 (3999 MiB) |
| Wall seconds limit | 18000 (5 hours) |
| Submitted time | 2025-10-31 08:00:43 |
| Site | NL_NIKHEF |
| Entry | VIRGO_NL_NIKHEF_juk |
| Last heartbeat | 2025-10-31 08:06:26 |
| From worker node | Hostname | wn-pep-013.farm.nikhef.nl |
| cpuinfo | Intel(R) Xeon(R) Gold 6148 CPU @ 2.40GHz |
| OS release | Scientific Linux release 7.9 (Nitrogen) |
| Processors | 1 |
| RSS bytes | 4194304000 (4000 MiB) |
| Wall seconds limit | 129600 (36 hours) |
| GPU | |
| Inner Apptainer? | True |
| Job state | jobscript_error |
| Started | 2025-10-31 08:02:35 |
| Input files | vd-protodune:np02vd_raw_run040285_0000_df-s03-d3_dw_0_20251028T162127.hdf5
|
| Jobscript | Exit code | 1 |
| Real time | 0m (0s) |
| CPU time | 0m (0s = 0%) |
| Max RSS bytes | 0 (0 MiB) |
| Outputting started | |
| Output files | |
| Finished | 2025-10-31 08:06:26 |
| Saved logs | justin-logs:235688.1-dunegpschedd02.fnal.gov.logs.tgz |
| List job events Cached HTCondor job logs |
Jobscript log (last 10,000 characters)
[09:04:16.373] D [ glue ] frame sink sees EOS
[09:04:16.373] D [ pgraph ] <Pgrapher:> graph execution complete
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.57 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.13 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.05 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.61 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.44 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.23 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.08 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.9 sec
[09:04:16.373] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:04:16.373] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:04:16.373] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:04:16.373] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[09:04:16.373] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:04:16.373] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[09:04:16.373] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:04:16.373] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:04:16.373] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:04:16.374] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:04:16.374] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:04:16.374] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:04:16.374] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:04:16.374] I [ timer ] Timer: Total node execution : 55.02000020630658 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 37242 traces tagged "gauss"
FrameSaver: q=8.86875e+06 n=768375 tag=gauss
wclsFrameSaver: saving 46271 traces tagged "wiener"
FrameSaver: q=9.56527e+06 n=733176 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2113 XUs and 2507 XVs -> 58 XUVs
C:0 T:1 2697 XUs and 2259 XVs -> 118 XUVs
C:0 T:2 838 XUs and 595 XVs -> 10 XUVs
C:0 T:3 1597 XUs and 1367 XVs -> 61 XUVs
C:0 T:4 9185 XUs and 11541 XVs -> 781 XUVs
C:0 T:5 53 XUs and 51 XVs -> 0 XUVs
C:0 T:6 558 XUs and 666 XVs -> 19 XUVs
C:0 T:7 36 XUs and 44 XVs -> 0 XUVs
C:0 T:8 654 XUs and 786 XVs -> 38 XUVs
C:0 T:9 570 XUs and 622 XVs -> 57 XUVs
C:0 T:10 75 XUs and 97 XVs -> 8 XUVs
C:0 T:11 743 XUs and 311 XVs -> 24 XUVs
C:0 T:12 364 XUs and 404 XVs -> 25 XUVs
C:0 T:13 1242 XUs and 1535 XVs -> 47 XUVs
C:0 T:14 765 XUs and 872 XVs -> 71 XUVs
C:0 T:15 415 XUs and 408 XVs -> 16 XUVs
1333 XUVs total
969 collection wire objects
1333 potential space points
Neighbour search...
30287 tests to find 8272 neighbours
Iterating with no regularization...
Begin: 1.59251e+10
0 1.5852e+10
1 1.58514e+10
Now with regularization...
Begin: 1.55418e+10
0 1.55417e+10
31-Oct-2025 09:04:44 CET Opened output file with pattern "%ifb_reco_stage1_%tc_keepup.root"
RawFrameSource: got 12288 raw::RawDigit objects
input nticks=8000 keeping as is
[09:05:06.553] D [ main ] executing 1 apps, thread limit 0:
[09:05:06.553] D [ main ] executing 1 apps, thread limit 0:
[09:05:06.553] D [ main ] executing app: "Pgrapher"
[09:05:06.553] D [ pgraph ] <Pgrapher:> executing graph
[09:05:06.553] D [ pgraph ] executing with 26 nodes
[09:05:06.557] D [ glue ] <FrameFanout:nfsp> call=2: input: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig" ] 0 tagged trace sets:[ ] cmm:[ ] output 0: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig0" ] 0 tagged trace sets:[ ] cmm:[ ] output 1: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig1" ] 0 tagged trace sets:[ ] cmm:[ ] output 2: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig2" ] 0 tagged trace sets:[ ] cmm:[ ] output 3: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig3" ] 0 tagged trace sets:[ ] cmm:[ ] output 4: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig4" ] 0 tagged trace sets:[ ] cmm:[ ] output 5: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig5" ] 0 tagged trace sets:[ ] cmm:[ ] output 6: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig6" ] 0 tagged trace sets:[ ] cmm:[ ] output 7: frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:05:06.558] W [ glue ] <ChannelSelector:chsel7> Untagged summary not supported, summary will be dropped.
[09:05:06.559] D [ glue ] <ChannelSelector:chsel7> input frame: ident=11 time=5 tick=512 with 12288 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ] output: frame: ident=11 time=5 tick=512 with 1536 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:05:06.559] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 input frame: frame: ident=11 time=5 tick=512 with 1536 traces. frame tags:[ "orig7" ] 0 tagged trace sets:[ ] cmm:[ ]
[09:05:06.559] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 init nticks=8000 tbinmin=0 tbinmax=8000
[09:05:06.594] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 load plane index: 0, ntraces=1536, input bad regions: 0
[09:05:08.085] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 load plane index: 1, ntraces=1536, input bad regions: 0
[09:05:09.615] D [sigproc ] <OmnibusSigProc:anode7sigproc7> call=2 load plane index: 2, ntraces=1536, input bad regions: 0
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 5.9378e-05 50.7701 101.54 50.7701 50.77 2
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.9378e-05 0.000113215 0.000167052 0.000113215 5.3837e-05 2
produce:tpcrawdecoder:PDVDTPCReader 12.7935 14.0751 15.3566 14.0751 1.28154 2
produce:triggerrawdecoder:PDVDTriggerReader4 0.292046 0.297579 0.303111 0.297579 0.00553259 2
produce:pdvddaphne:DAPHNEReaderPDVD 0.00039633 0.00056923 0.000742131 0.00056923 0.000172901 2
produce:ophit:OpHitFinder 6.978e-05 0.00025777 0.00044576 0.00025777 0.00018799 2
produce:opflash:OpFlashFinderVerticalDrift 5.5819e-05 0.000179966 0.000304113 0.000179966 0.000124147 2
produce:wclsdatavd:WireCellToolkit 56.2702 56.2702 56.2702 56.2702 0 1
produce:gaushit:GausHitFinder 1.05559 1.05559 1.05559 1.05559 0 1
produce:nhitsfilter:NumberOfHitsFilter 0.000500725 0.000500725 0.000500725 0.000500725 0 1
produce:reco3d:SpacePointSolver 7.79866 7.79866 7.79866 7.79866 0 1
produce:hitpdune:DisambigFromSpacePoints 0.133087 0.133087 0.133087 0.133087 0 1
produce:pandora:StandardPandora 18.4712 18.4712 18.4712 18.4712 0 1
produce:pandoraTrack:LArPandoraTrackCreation 0.689285 0.689285 0.689285 0.689285 0 1
produce:pandoraGnocalo:GnocchiCalorimetry 0.0275457 0.0275457 0.0275457 0.0275457 0 1
[art]:TriggerResults:TriggerResultInserter 6.9979e-05 6.9979e-05 6.9979e-05 6.9979e-05 0 1
end_path:out1:RootOutput 2.3226e-05 2.3226e-05 2.3226e-05 2.3226e-05 0 1
end_path:out1:RootOutput(write) 3.96193 3.96193 3.96193 3.96193 0 1
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 8589.84 MB
Peak resident set size usage (VmHWM): 6716.96 MB
Details saved in: 'mem.db'
====================================================================================================
%MSG-s ArtException: PostEndJob 31-Oct-2025 09:06:02 CET ModuleEndJob
---- EventProcessorFailure BEGIN
EventProcessor: an exception occurred during current event processing
---- ScheduleExecutionFailure BEGIN
Path: ProcessingStopped.
---- BadAlloc BEGIN
A bad_alloc exception was thrown while processing module WireCellToolkit/wclsdatavd run: 40285 subRun: 1 event: 11
The job has probably exhausted the virtual memory available to the process.
---- BadAlloc END
Exception going through path produce
---- ScheduleExecutionFailure END
---- EventProcessorFailure END
%MSG
Art has completed and will exit with status 1.
Error in reco1 