beam current incorrect in some runs about rcdb HOT 19 CLOSED

I can hack the code so that if add_condition(...'beam_current') is called, the change is logged into DB with time process ID-s and etc. Kind of brutal way, but maybe we could figure out the problem. Because I looked at logs of 10907-10911 all of them have some valid values.

(For 10911)

Adding cnd 'beam_current'='76.9148'

in /tmp directory I see the last entry for the run in RCDB. This mean that these values should be there

from rcdb.

It looks like these current numbers are wrong across the board. I'll look into it more and fix the wrong values.

I remember @DraTeots added some more logging to these scripts. Is it turned on, and if so where can I look at them to see why these calls are failing?

from rcdb.

Beam current values in RCDB are fixed. They started going off around run 10585, not consistently though. This might have been around the time I last fixed the current values?

current_values.txt

from rcdb.

Logs for running RCDB on Run 10906 are located on gluon100 in /tmp folder.

cat /tmp/hdops_RCDB.10906

Wed Mar  9 07:33:23 EST 2016
----- > run_update_rcdb  ENTER <---- 
ENV_RAWDATA_DIR=export RAWDATA_DIR=/gluex/raid/rawdata  : /gluex/raid/rawdata 
ENV_RUN_PERIOD=export RUN_PERIOD=RunPeriod-2016-02    : RunPeriod-2016-02
get_host:: comp=ERsoftROC use host=gluonraid1
 start parse_coda_log  --modules=update_epics  --udl=cMsg://gluon100.jlab.org:45000/cMsg/hdops?regime=low&cmsgpassword=hdops 
-------> run_update_rcdb EXIT Wed Mar  9 07:33:33 EST 2016 <-------
Wed Mar  9 07:33:33 EST 2016
LOG=/home/hdops/CDAQ/daq_dev_v0.31/daq/cool/hdops/ddb/run-log/hdops/current_run.log
RCDB PATH=/home/hdops/CDAQ/daq_dev_v0.31/daq/rcdb
MODULES = update_epics
UDL = cMsg://gluon100.jlab.org:45000/cMsg/hdops?regime=low&cmsgpassword=hdops
VERBOSE = --verbose
------------- rcdb: run_end ---------------------
Parsing coda_xml_log_file='/home/hdops/CDAQ/daq_dev_v0.31/daq/cool/hdops/ddb/run-log/hdops/current_run.log'
Parsing CODA file '/home/hdops/CDAQ/daq_dev_v0.31/daq/cool/hdops/ddb/run-log/hdops/current_run.log'
Processing xml tree 
Run number '10906'
Run start time is '2016-03-09 06:32:53'
Setting end time '2016-03-09 07:33:26' to run '10906'
Update time is '2016-03-09 07:33:26'
Run config file extracted from rtvs 'FCAL_BCAL_PS_m7.conf'
No <run-end> section found in file
Unable to find <end-comment> section
Parsed coda_xml_log_file='/home/hdops/CDAQ/daq_dev_v0.31/daq/cool/hdops/ddb/run-log/hdops/current_run.log'. run='<Run number='10906'>', run_config_file='/home/hdops/CDAQ/daq_dev_v0.31/daq/config/hd_all/FCAL_BCAL_PS_m7.conf'
Adding coda_xml_log_file to DB
Processing configuration file
|- Content is None, assuming using file '/home/hdops/CDAQ/daq_dev_v0.31/daq/cool/hdops/ddb/run-log/hdops/current_run.log'
|- File '/home/hdops/CDAQ/daq_dev_v0.31/daq/cool/hdops/ddb/run-log/hdops/current_run.log' is getting overwritten
Adding run_config_file to DB
Processing configuration file
|- Content is None, assuming using file '/home/hdops/CDAQ/daq_dev_v0.31/daq/config/hd_all/FCAL_BCAL_PS_m7.conf'
|- File '/home/hdops/CDAQ/daq_dev_v0.31/daq/config/hd_all/FCAL_BCAL_PS_m7.conf' found in DB by id: '5627'
|- File already associated with run'<Run number='10906'>'
Performing update_epics.py
Running 'update_rcdb_conds(db=<rcdb.provider.ConfigurationProvider object at 0x13e7950>,   run=<Run number='10906'>)'
Requesting beam_current between  '2016-03-09 06:32:53' and '2016-03-09 07:33:26'
Requesting beam_current subprocess flags: '['myStats', '-b', '2016-03-09 06:32:53', '-e', '2016-03-09 07:33:26', '-l', 'IBCAD00CRCUR6']'
Adding cnd 'radiator_type'='JD70-119 20um'
Adding cnd 'status'='-1'
Adding cnd 'ps_converter'='Retracted'
Adding cnd 'solenoid_current'='1199.72452794'
Adding cnd 'coherent_peak'='9000.0'
Adding cnd 'beam_energy'='12112.99996'
Adding cnd 'radiator_id'='7'
Adding cnd 'target_type'='FULL & Ready'
Adding cnd 'polarization_direction'='PERP'
Adding cnd 'radiator_index'='11.0'
Adding cnd 'beam_current'='113.218'
Adding cnd 'polarimeter_converter'='Be 750um'
Adding cnd 'collimator_diameter'='5.0mm hole'
Committed to DB. End of update_rcdb_conds()

Run 10585 started 2016-02-26 17:42:40. There where several bug fixes of getting beam_current before the date. The list of changes are:

1. Logging module for update_epics.py
2. Logic of getting end time to get beam_current
3. Remove supporting of #12

From the first glance item 2 could be the issue, I see in the log above that the run start and end times where correctly given to myStats

from rcdb.

That's odd - the correct value should have been written to the RCDB. I'm not sure who would have changed it. I'll keep a close eye on these values once we start getting beam again and see if that yields more information.

from rcdb.

That's a good next step, but I think we should verify that this problem is
still happening for new runs before implementing a hack like that.

On Fri, Mar 11, 2016 at 12:43 PM Dmitry Romanov [email protected]
wrote:

I can hack the code so that if 'beam_current' is changed, the change is
logged into DB with time process ID-s and etc. Kind of brutal way, but
maybe we could figure out the problem. Because I looked at logs of
10907-10911 all of them have some valid values.

(For 10911)

Adding cnd 'beam_current'='76.9148'

in /tmp directory I see the last entry for the run in RCDB. To this mean
that these values should be there.

—
Reply to this email directly or view it on GitHub
#18 (comment).

from rcdb.

Yes, sure.

While there is not beam, I plan to move RCDB code to git-hub. There is also a DB schema change and web site update (#10 included). Finally all update scripts (including update_epics) will have a context (go, update, run-end). Maybe the issue is fixed already, whatever it was.

from rcdb.

I checked a few recent runs. For 11071, the value in RCDB (35.0343) does not match the correct value (128.758) or the value reported in the log file /tmp/hdops_RCDB.11071 (128.758).

from rcdb.

Ok. I'll add DB logging of values to figure out the problem

from rcdb.

If it's helpful, both runs 11107 and 11108 are wrong.

from rcdb.

Run 11104 shows a current of 0.42 nA, but this must be wrong. The average of the run is about 137 nA, but there is a nice distribution around 200 nA with periods of zero beam. See Log 3393789

from rcdb.

Newer runs are still showing this problem. Let me know if it's okay to fix the beam currents in these runs or if you still need them fir debugging.

from rcdb.

FYI, I've updated the values in the RCDB to prepare for calibration running.

from rcdb.

Actually, I'm trying to update the values in the database, but the new beam current values are refusing to show up.

from rcdb.

The new DAQ update scheme is shipped. Lets look if those wrong records appear.

from rcdb.

The beam current in the test runs today looks correct. Will keep an eye on this.

from rcdb.

This is definitely looking better. Over the past day, just one run with an incorrect beam current:

run = 11366 current in RCDB = 123.46 correct current = 135.72

WIll check again on Monday.

from rcdb.

I implemented DB logging, so now each daq update spams several messages to DB including setting beam_current.

When you notice wrong beam_current the next time, please put here, what run it was.

The logs page
https://halldweb.jlab.org/rcdb/logs/

from rcdb.

Everything over the weekend is correct. I'll still keep an eye on this through the end of the run period, but will close this issue for now.

from rcdb.