Issues with beam helicity algorithm and JANA2

[sdobbs]

We're trying to port an algorithm to calculate the electron beam helicity to halld_recon and are running into some issues. This port is making two changes: (1) going from JANA to JANA2; (2) running the algorithm in a factory instead of in a plugin.

I think the main problem is that the algorithm needs to keep some global state, in order to decode the delayed helicity signal. What would be the best way to accomplish this in a JANA2 factory?

[faustus123]

I think I would need more information on this to better respond. If there is global state that is changed by the factory itself then it would seem race conditions would prevent reproducibility. What is the origin of the information that goes into the global state? (EPICS events?)

[kliv]

The process() in the thread needs to know if the current event id is the latest, or if a later event has been processed in a different thread. It does this by writing to some global variable (eg fLatestEvent - see plugins/monitoring/HELI_online/JEventProcessor_HELI_online.cc and .h
It needs to know this to work out whether helicity bits have flipped in the timeline. It works in the plugin with jana1, but not jana2.

[sdobbs]

FWIW, the current dev branch is sdobbs_helicity_jana2

[nathanwbrei]

@sdobbs I'm taking a look at your branch, will follow up with questions for you in a bit

[sdobbs]

Instructions from Ken on how to reproduce the results:

The setup file in src/plugins/monitoring/HELI_online/helicity_setup.txt
is needed.
It should be in the working directory, or can be specified on the
command line with
-PHELI:SETUP (plugin version)
-PHELIF:SETUP (factory version)

To run as a plugin:
hd_root -PPLUGINS=HELI_online,EPICS_dump -PHELI:VERBOSE=2
-PHELI:LOG=plugin_test.log -PTT:NO_CCDB=1
-PTT:XML_FILENAME=/group/halld/Users/jrsteven/TranslationTable/tt_helicity.xml
/cache/mss/halld/RunPeriod-2023-01/rawdata/Run121100/hd_rawdata_121100_000.evio
-Pjana:nevents=5000 -PEVIO:NTHREADS=4 -PNTHREADS=8 -o test.root

To run from factory to fill rest file

hd_root -PPLUGINS=danarest,EPICS_dump -PHELIF:VERBOSE=2
-PHELIF:LOG=factory_test.log -PTT:NO_CCDB=1
-PTT:XML_FILENAME=/group/halld/Users/jrsteven/TranslationTable/tt_helicity.xml
/cache/mss/halld/RunPeriod-2023-01/rawdata/Run121100/hd_rawdata_121100_000.evio
-Pjana:nevents=5000 -PEVIO:NTHREADS=4 -PNTHREADS=8 -o test.root

The log files are produced if VERBOSE=2.
They contain the information to make lookup tables. Currently they do this:

#Seed 0
1 0 0 0 0 160 1 0 St
15 1 0 0 1 0 0 0 0 160 1 0 St
24 1 0 0 1 0 0 0 0 160 1 0 St
38 1 0 0 1 0 0 0 0 160 1 0 St
83 1 0 0 1 0 0 0 0 160 1 0 St
90 1 0 0 1 0 0 0 0 160 1 0 St
105 1 0 0 1 0 0 0 0 160 1 0 St
116 1 0 0 1 0 0 0 0 160 1 0 St
161 1 1 1 1 0 0 0 0 160 1 0 St
176 1 1 1 1 0 0 0 0 160 1 0 St
184 1 1 1 1 0 0 0 0 160 1 0 St
....

Notice there are events missing.

Here's an example from a previous file with the working plugin under jana1.

npc80.kl> more
/w/work4/jlab/halld/data/2023-01/hel/120395/helicity_120395_079.log
123514522 1 0 1 -1 0 0 0 0 160 1 0 La
123514526 1 0 1 -1 0 0 0 0 160 1 0 La
123514529 1 0 1 -1 0 0 0 0 160 1 0 La
123514530 1 0 1 -1 0 0 0 0 160 1 0 La
123514525 1 0 1 -1 0 0 0 0 160 1 0 St
123514527 1 0 1 -1 0 0 0 0 160 1 0 St
123514532 1 0 1 -1 0 0 0 0 160 1 0 La
123514524 1 0 1 -1 0 0 0 0 160 1 0 St
123514528 1 0 1 -1 0 0 0 0 160 1 0 St
123514523 1 0 1 -1 0 0 0 0 160 1 0 St
123514521 1 0 1 -1 0 0 0 0 160 1 0 St
123514531 1 0 1 -1 0 0 0 0 160 1 0 St
123514533 1 0 1 -1 0 0 0 0 160 1 0 La
....
....

The events are all there, but jumbled up in order. (The St/La flag means
standard or latest event so far).

[sdobbs]

@nathanwbrei - I thought a little more about the discussion at the C&P meeting today, and wanted to propose this way forward:

• We could indeed do the helicity calculation in the danarest plugin and write it out there - that would sidestep all of these factory issues
• In that case, we probably want to abstract the algorithm implemented in the HELI_online plugin, so that we don't copy and paste all of the code - probably this could be pulled into its own class.
• I think the HELI_online plugin does still need to be fixed to work with JANA2
• We would need to extend DEventWriterHDDM::Write_HDDMEvent() to pass in the helicity info (it's just an int). While we could do that directly as an optional argument, I think it makes sense to implement a more generic solution while we are doing this. Maybe something like passing an optional list of callback functions?

Let me know what you think.

[RaiqaRasool]

Hi @sdobbs,

I found the reason for the incorrect results in HELI_online—it was a mistake on my part during porting to JANA2. In JANA1, brun receives the run number directly, but in JANA2 (BeginRun), I needed to retrieve it from the event. However, I mistakenly accessed the event number instead of the run number:

void JEventProcessor_HELI_online::BeginRun(const std::shared_ptr<const JEvent>& event) {
    auto runnumber = event->GetEventNumber();  // Incorrect
    // remaining code
}

I’ve now corrected this to properly retrieve the run number:

void JEventProcessor_HELI_online::BeginRun(const std::shared_ptr<const JEvent>& event) {
    auto runnumber = event->GetRunNumber();  // Corrected
    // remaining code
}

With this fix, JANA1 and JANA2 now produce identical results when running with -PEVIO:NTHREADS=1 -PNTHREADS=1.

However, when using the multi-threaded configuration from the example (-PEVIO:NTHREADS=4 -PNTHREADS=8), I notice some variations between runs, even within JANA1 itself. The differences include:

• #NewBit value: fEventNo value in NewBit row alternates between 165 and 163.
• Event row values:

  10    1 0 0 1 0 0 0 0 160 1 0 La  
  100   1 0 0 1 0 0 0 0 22 1 0 St  
  1000  1 1 1 1 0 0 0 0 22 1 0 St  
  

dHelBits[8] = (int)(fEventRate/1000) values fluctuate between 160, 22, and 23, and tags (La/St) change for the same event across different runs.

Since multi-threaded execution doesn't guarantee event processing order, my guess is this might be the expected behavior. I’d appreciate your input—do you see anything concerning here? If everything looks fine, I’ll push the fix to a branch and create a PR while documenting this behavior.

Thanks!

[nathanwbrei]

Thanks @RaiqaRasool . I think the big question for @sdobbs is whether we can tolerate these variations in the output. If the algorithm needs to run single-threaded there's no point converting it to a JFactory.

(FWIW I'm hatching a plan for how we could in principle run the heilicty JEventProcessor immediately downstream of the JEventSource, so that it sees an ordered stream of events and processes them sequentially. This would require EVIO:NTHREADS=1 (as otherwise the event stream is once again unordered) but WOULDN'T require NTHREADS=1.

[kliv]

Hi Raiqa, Nathan
Some responses on helicity discussions.
Firstly - it should not not need to run single threaded. In fact a lot of head scratching went in to figuring out how to make it work multi-threaded. (see below). There's also a document on this at https://halldweb.jlab.org/doc-private/DocDB/ShowDocument?docid=6784

The plugin was made as a development tool, primarily for the 2023 data, where only the 4 basic helicity bits were going in to the event by event data. At the time, the plan was to test and debug with the plugin, and then use it to get some quick and dirty helicity lookup tables for Peter to analyze and make the Alpha proposal. This was done.

The next step was to be to move this to a factory where it could be used in reconstruction to write the data to REST files. For that reason I went to some effort to make the plugin work in multi-threaded mode, and cope with the jumbled up sequence of events. The move to the factory was to also have multi-threaded support, and to read setup and EPICS variables from CCDB, as opposed so a setup file (as in the plugin method).

Then - along came news of a magical decoder board! We decided to leave this old plugin stuff alone.

Now there's a desire to reconstruct the 2023 data and inject the helicity information into the HDDM files, and I was asked to go back and move the plugin functionality to the factory. Seemed reasonable straightforward. I moved stuff over and it all compiled with jana2 ... but much of the output was missing or wrong - with the plugin and factory versions. That all seems to be loss of persistence, where variables don't seem to be holding data from one event to the next.

Here's what does work:
running the plugin, single threaded still writes the 4 basic helicity bits into a log file, which can be used to make lookup tables for analysis. This could already be used if there urgent need to send reconstruction jobs for the 2023 data.

Future:
I think the minimum is to read the 4 basic bits as before, plus decoded helicity and random seed from the decoder board, and include these in the REST file. None of that is thread sensitive, since no time history is required. It would really be desirable to also include the current plugin functionality and decoded helicity in the same factory and put that data in the REST file until we trust the board.

I've not had a chance to test the updates discussed. I'm actually on vacation, and won't get back to this until Tuesday.

Thanks to all who are trying to fix this.
Ken

[RaiqaRasool]

Hi Ken,

Welcome back! Sorry for the late reply—I wanted to resume our discussion after your return from the vacations.

From what I understand, you expect the helicity plugin to work correctly in both single-threaded and multi-threaded modes. However, I’m seeing the behavior I described earlier even in halld_recon code with JANA1, which hasn’t been modified by us.

Hi @sdobbs,

I found the reason for the incorrect results in HELI_online—it was a mistake on my part during porting to JANA2. In JANA1, brun receives the run number directly, but in JANA2 (BeginRun), I needed to retrieve it from the event. However, I mistakenly accessed the event number instead of the run number:

void JEventProcessor_HELI_online::BeginRun(const std::shared_ptr& event) {
auto runnumber = event->GetEventNumber(); // Incorrect
// remaining code
}
I’ve now corrected this to properly retrieve the run number:

void JEventProcessor_HELI_online::BeginRun(const std::shared_ptr& event) {
auto runnumber = event->GetRunNumber(); // Corrected
// remaining code
}
With this fix, JANA1 and JANA2 now produce identical results when running with -PEVIO:NTHREADS=1 -PNTHREADS=1.

However, when using the multi-threaded configuration from the example (-PEVIO:NTHREADS=4 -PNTHREADS=8), I notice some variations between runs, even within JANA1 itself. The differences include:

• #NewBit value: fEventNo value in NewBit row alternates between 165 and 163.
• Event row values:

  10    1 0 0 1 0 0 0 0 160 1 0 La  
  100   1 0 0 1 0 0 0 0 22 1 0 St  
  1000  1 1 1 1 0 0 0 0 22 1 0 St  
  

dHelBits[8] = (int)(fEventRate/1000) values fluctuate between 160, 22, and 23, and tags (La/St) change for the same event across different runs.

Since multi-threaded execution doesn't guarantee event processing order, my guess is this might be the expected behavior. I’d appreciate your input—do you see anything concerning here? If everything looks fine, I’ll push the fix to a branch and create a PR while documenting this behavior.

Thanks!

The only observed differences are in fEventRate and fEventNo for the NewBit and Latest/Standard tags—otherwise, everything remains consistent. My suspicion is that these discrepancies arise due to variations in event processing order, e.g. an event is marked as Latest in one run and Standard in another due to the order in which it is processed.

I’ve attached output comparisons of multiple JANA1 and JANA2 runs for reference. I’d appreciate it if you could review them and verify whether my suspicions are correct:

JANA1 vs JANA2 – 8 Threads (Multiple Runs)

• Comparison 1
• Comparison 2
• Comparison 3

If you compare JANA1 outputs across multiple runs, you’ll notice variations in values.

JANA1 vs JANA2 – 1 Thread

• Comparison

Here, none of the discrepancies observed in the multi-threaded case appear, and results remain consistent across runs.

JANA1 vs JANA1 (1 Thread vs 8 Threads)

• Comparison

Looking forward to your thoughts!

Thanks,

[kliv]

Hi Raiqa,
I think we can declare the plugin to be working.
Thank a lot for digging into this. I've just had a look.
Firstly - I should have spotted the event->GetRunNumber() bug myself! Silly.
Second - it's expected that the events are out of sequence in the multi-threaded analysis. So the behaviour you see in the log files is OK. (Also, the eventRate number is not reliable, and a relic, so we shouldn't focus on that).

The best way to check the output is to look at the values obtained for the PseudoRandom seed. This requires 30 successive helicity pattern bits to be accummulated, and is a good test on whether the code is working. Each time a new bit is acquired it writes a comment line into the helicity.log file like this:
#NewBit 227122, Hel 1, Got 22 bits 76393

Only when 30 bits have been read can the random seed be used and the undelayed helicity predicted.

So looking for these lines in a log file produced from the earlier pass (over a year ago with jana1 -PEVIO:NTHREADS=4 -PNTHREADS=8), we get:

npc80.kl> grep #New helicity_120400_000.log | more

#NewBit 2722, Hel 0, Got 1 bits 0
#NewBit 13522, Hel 0, Got 2 bits 0
#NewBit 24175, Hel 0, Got 3 bits 0
#NewBit 34882, Hel 0, Got 4 bits 0
...
#NewBit 290602, Hel 1, Got 28 bits 4889213
#NewBit 301173, Hel 0, Got 29 bits 9778426
#NewBit 311882, Hel 1, Got 30 bits 19556853
...

Now with jana2 -PEVIO:NTHREADS=4 -PNTHREADS=8:

ifarm2402|kliv>grep #New hel_120400_4_8.log | more
#NewBit 2725, Hel 0, Got 1 bits 0
#NewBit 13526, Hel 0, Got 2 bits 0
#NewBit 24247, Hel 0, Got 3 bits 0
#NewBit 34884, Hel 0, Got 4 bits 0
...
#NewBit 290571, Hel 1, Got 28 bits 4889213
#NewBit 301208, Hel 0, Got 29 bits 9778426
#NewBit 311870, Hel 1, Got 30 bits 19556853
...

Now with jana2 -PEVIO:NTHREADS=1 -PNTHREADS=1:

ifarm2402|kliv>grep #New hel_120400_1_1.log
#NewBit 2725, Hel 0, Got 1 bits 0
#NewBit 13526, Hel 0, Got 2 bits 0
#NewBit 24176, Hel 0, Got 3 bits 0
#NewBit 34884, Hel 0, Got 4 bits 0
...
#NewBit 290575, Hel 1, Got 28 bits 4889213
#NewBit 301204, Hel 0, Got 29 bits 9778426
#NewBit 311870, Hel 1, Got 30 bits 19556853
...

Notice that the event numbers (2nd column) where the NewBits are obtained are slightly different in each run due to multi-threading, but the random seed (last column) is the same. That's what matters.

Plugin vs factory

In the plugin, Init()/Finish() seem to be called only once, BeginRun()/EndRun() seem to be called only once per run (independent of the number of threads) - or maybe only for the 1st event processed, then working out the run number from that and assuming it doesn't change? ProvessEvent() is called from each thread, but still has access to class variables (ie doesn't seem to keep a private copy).

In the factory, everything seems to be contained by every thread, and the class variables as local to each thread. Or I don't know how to make them global. If someone can explain to me how to have the same behaviour in factory as in the plugin, or point me to an example, I can move this to the factory and then it will be possible to push the information to REST files.