test: track usage of hard-coded scaler clock frequencies

[c-dilks]

The DSC2 and STRUCK scaler clock frequencies are stored in CCDB, but they are also hard-coded. This branch adds a magic number to each of the hard-coded assignments, and checks for that magic number when they're (likely) used. Printouts to stderr starting with clockbug are used to investigate.

[baltzell]

What's the measured value of the hardware clock in question? This isn't affected by both DCS2 and Struck scalers.

[c-dilks]

I'm more concerned about ambiguity in the code as to whether a CCDB value is used or a hard-coded value is used here. Even if the real clock frequency never changed, we should either use a CCDB value everywhere, or define the hard-coded frequency in one single place only; the current software both uses a CCDB value and uses hard-coded values defined in 3 places, and the value is mutable.

Here are the frequencies:

• DSC2
  • according to CCDB:
    • 1 MHz before run 14776 (from 2021 HPS run)
    • 100 kHz afterward
  • clock vs. timestamp indicates RG-A Spring 2018 may have used ~100 MHz
• STRUCK
  • always 1 MHz according to CCDB

If the hard-coded 1 MHz is used for DSC2 for runs after 14776 to estimate the charge, that's a problem.

This PR's branch should be tested on all the usual call graphs, including:

• recon-util / run-clara
• postprocess
• running with recharge true vs. false (rebuild-scalers)

[baltzell]

Note the DSC2 and Struck are different hardware, and can have different clocks.

[c-dilks]

Happens in clara, with local RG-D test file (as done in the CI)

rm -vfr tmp
coatjava/bin/run-clara \
-y etc/services/rgd-clarode.yml \
-t 8 \
-n 500 \
-c ./clara \
-o ./tmp \
validation/advanced-tests/data/evio/rg-d/clas_018779.evio.01339
sep
grep \
--color \
'^clockbug.*' \
$(find tmp/log -type f -name '*dpe.log')
sep
coatjava/bin/run-groovy scan.groovy tmp/rec_clas_018779.evio.01339.hipo

relevant output:

│================================================================================== │
│clockbug [Dsc2Scaler]: ----------- │
│clockbug [Dsc2Scaler]: clockFreq OK (value=100000.000000) │
│clockbug [Dsc2Scaler]: toString: clock=615111581/568492956 fcup=231343920/212190933 slm=67604336/61973466 │
│clockbug [Dsc2Scaler]: fcup_offset=440.300000 fcup_slope=906.200000 fcup_atten=1.000000 │
│clockbug [Dsc2Scaler]: clockFreq=100000.000000 beamCharge=252301.460725 beamChargeGated=231392.472429 │
│clockbug [StruckScaler]: ----------- │
│clockbug [StruckScaler]: used hard-coded clockFreq from StruckScaler() │
│clockbug [StruckScaler]: toString: i=A h=-1 q=1 clock=33330/30966 fcup=1391/1283 slm=405/387 │
│clockbug [StruckScaler]: fcup_offset=440.300000 fcup_slope=906.200000 fcup_atten=1.000000 │
│clockbug [StruckScaler]: clockFreq=1000000.000000 beamCharge=1.518787 beamChargeGated=1.400757 │
│clockbug [Dsc2Scaler]: ----------- │
│clockbug [Dsc2Scaler]: used hard-coded clockFreq from Dsc2Scaler(bank,table,table,seconds) │
│clockbug [Dsc2Scaler]: toString: clock=615111581/568492956 fcup=231343920/212190933 slm=67604336/61973466 │
│clockbug [Dsc2Scaler]: fcup_offset=440.300000 fcup_slope=906.200000 fcup_atten=1.000000 │
│clockbug [Dsc2Scaler]: clockFreq=1000000.000000 beamCharge=252527.966245 beamChargeGated=231621.149872 │
│================================================================================== │ │
│ │
│**************************************** │
│* Running COATJAVA Groovy Script * │
│**************************************** │
│ │
│Picked up _JAVA_OPTIONS: -Djava.io.tmpdir=/farm/home/dilks/.tmpfs/java.io.tmpdir -Dorg.sqlite.tmpdir=/farm/home/dilks/.tmpfs/org.sqlite.tmpdir │
│reader:: *****>>>>> openning file : tmp/rec_clas_018779.evio.01339.hipo │
│reader:: ***** dictionary entries : 75 │
│reader:: ************ file size : 2068948 │
│reader:: **** scan trailer #bytes : 88 │
│reader:: ***** number of records : 1 │
│reader:: ***** number of events : 500 │
│beamCharge=252527.97 beamChargeGated=231621.16 │

• yes, RG-D charge is already bogus
• initially, 100 kHz is used and the gated charge is 231392
• then it's redone with 1 MHz, and gated charge is 231621
• very small difference for this case

[c-dilks]

Testing decoder with RG-C (but with the current coatjava version; they cooked with v10 actually)

rm rgc.hipo -f
coatjava/bin/decoder \
-l FINE \
-n 10000 \
-o rgc.hipo \
/cache/clas12/rg-c/data/clas_016330/clas_016330.evio.00808 2>&1| tee clockbug.log
grep --color '^clockbug.*' clockbug.log

returns

│clockbug [Dsc2Scaler]: ----------- │
│clockbug [Dsc2Scaler]: clockFreq OK (value=100000.000000) │
│clockbug [Dsc2Scaler]: toString: clock=1063236791/1034186686 fcup=41387232/40195882 slm=78998292/76636312 │
│clockbug [Dsc2Scaler]: fcup_offset=433.930000 fcup_slope=906.200000 fcup_atten=1.000000 │
│clockbug [Dsc2Scaler]: clockFreq=100000.000000 beamCharge=40579.925616 beamChargeGated=39404.365166 │
│clockbug [StruckScaler]: ----------- │
│clockbug [StruckScaler]: used hard-coded clockFreq from StruckScaler() │
│clockbug [StruckScaler]: toString: i=A h=1 q=1 clock=33330/32564 fcup=143/142 slm=288/278 │
│clockbug [StruckScaler]: fcup_offset=433.930000 fcup_slope=906.200000 fcup_atten=1.000000 │
│clockbug [StruckScaler]: clockFreq=1000000.000000 beamCharge=0.141842 beamChargeGated=0.141105 │
│clockbug [Dsc2Scaler]: ----------- │
│clockbug [Dsc2Scaler]: used hard-coded clockFreq from Dsc2Scaler(bank,table,table,seconds) │
│clockbug [Dsc2Scaler]: toString: clock=1063236791/1034186686 fcup=41387232/40195882 slm=78998292/76636312 │
│clockbug [Dsc2Scaler]: fcup_offset=433.930000 fcup_slope=906.200000 fcup_atten=1.000000 │
│clockbug [Dsc2Scaler]: clockFreq=1000000.000000 beamCharge=40719.025851 beamChargeGated=39546.910464 │

~0.3% difference in the charge

[c-dilks]

issue resolved by #1153