ELOG Midas

Back Midas Rome Roody Rootana

Midas DAQ System, Page 89 of 155

Not logged in

Find | Login | Help

Full | Summary | Threaded | Hide attachments

3081 Entries

Goto page Previous 1, 2, 3 ... 88, 89, 90 ... 153, 154, 155 Next

Partial refactoring of ODB code

> One additional comment: In the 90's when I developed this code, locking was expensive.
> Now the world has changed, we can do almost a million locks a second.

I am not sure this is quite true. The CPU can execute 3000 million operations per second (3GHz CPU, assuming 1 op/Hz),
so 1 lock operation is worth 3000 normal operations. Of course cache misses and branch mispredictions mess up
this simple arithmetic...

But I think cost of mutex lock/unlock can be easily measured. (hmm... now I am curious).

Bigger question is architectural, nested/recursive locks is definitely a bad thing to do (not just my opinion).

But closer to home, as I implemented "write protected" ODB, lock/unlock suddenly has to do MMU operations
(map unmap memory) and this is *very* expensive.

Also as we start doing more multithreading, lock contention is becoming a problem, and the standard solution
is to implement read-locks and write-locks. (everybody holding a read-lock can read ODB at the same time
without waiting).

So, moving in the direction of separate read and write locks and write-protected (and/or read-protected) ODB shared memory,
all points in the direction of reworking of ODB locks in the direction of removing the need for nested/recursive locks.

I think me and Stefan are in agreement here.

K.O.

Partial refactoring of ODB code

> I am not sure this is quite true. The CPU can execute 3000 million operations per second (3GHz CPU, assuming 1 op/Hz),
> so 1 lock operation is worth 3000 normal operations. Of course cache misses and branch mispredictions mess up
> this simple arithmetic...

You can try that with "t1" in odbedit. This times the number of db_get_data() calls midas can do per second. On my MacBook Pro I get 470'000 
accesses per second.

Params not initialized when starting sequencer

Good afternoon,

After updating Midas to the latest develop commit 
(0f5436d901a1dfaf6da2b94e2d87f870e3611cf1) we found out a bug when starting 
sequencer. If we have a simple loop from start value to stop value and step 
size, just printing the value at each iteration, we see everything good (see 
first attachment). Then we included another script though, which contains 
several subroutines we defined for our detector, and we try to run the same 
script. Unfortunately after this the parameters seem uninitialized, and the 
value at each loop does not make sense (see second attachment). Also, sometimes 
when pressing run the set parameter window would pop-up, but sometimes not.

The script is this one:

>>>
COMMENT Test script to check for a specific bug

INCLUDE global_basic_functions

#CALL setup_paths
#CALL generate_DUT_params

PARAM lv_start, "Start of LV", 1.8
PARAM lv_stop, "Stop of LV", 2.1
PARAM lv_step, "Step of LV", 0.02

n_iterations = (($lv_stop - $lv_start)/$lv_step)

MSG "Parameters:"
MSG $lv_start
MSG $lv_stop
MSG $lv_step
MSG $n_iterations

MSG "Start of looping"

LOOP n, $n_iterations
   lv_now = $lv_start + $n * $lv_step
   MSG $lv_now
   WAIT SECONDS, 1
ENDLOOP
<<<

and the only difference comes from commenting the line:

>>>
INCLUDE global_basic_functions
<<<

as global_basic_functions is defined as a LIBRARY and it includes 75 (!) 
subroutines...

Is it possible that when loading a large script it messes up the loading of 
parameters?

Thank you very much,
Regards,
Luigi.

Attachment 1: midas_sequencer_ok.png

Attachment 2: midas_sequencer_buggy2.png

Params not initialized when starting sequencer

Could you please export and send me the /Sequencer ODB tree (or just /Sequencer/Param and /Sequencer/Variables) in both cases while the sequence is running. 

thanks,
Zaher


> Good afternoon,
> 
> After updating Midas to the latest develop commit 
> (0f5436d901a1dfaf6da2b94e2d87f870e3611cf1) we found out a bug when starting 
> sequencer. If we have a simple loop from start value to stop value and step 
> size, just printing the value at each iteration, we see everything good (see 
> first attachment). Then we included another script though, which contains 
> several subroutines we defined for our detector, and we try to run the same 
> script. Unfortunately after this the parameters seem uninitialized, and the 
> value at each loop does not make sense (see second attachment). Also, sometimes 
> when pressing run the set parameter window would pop-up, but sometimes not.
> 
> The script is this one:
> 
> >>>
> COMMENT Test script to check for a specific bug
> 
> INCLUDE global_basic_functions
> 
> #CALL setup_paths
> #CALL generate_DUT_params
> 
> PARAM lv_start, "Start of LV", 1.8
> PARAM lv_stop, "Stop of LV", 2.1
> PARAM lv_step, "Step of LV", 0.02
> 
> n_iterations = (($lv_stop - $lv_start)/$lv_step)
> 
> MSG "Parameters:"
> MSG $lv_start
> MSG $lv_stop
> MSG $lv_step
> MSG $n_iterations
> 
> MSG "Start of looping"
> 
> LOOP n, $n_iterations
>    lv_now = $lv_start + $n * $lv_step
>    MSG $lv_now
>    WAIT SECONDS, 1
> ENDLOOP
> <<<
> 
> and the only difference comes from commenting the line:
> 
> >>>
> INCLUDE global_basic_functions
> <<<
> 
> as global_basic_functions is defined as a LIBRARY and it includes 75 (!) 
> subroutines...
> 
> Is it possible that when loading a large script it messes up the loading of 
> parameters?
> 
> Thank you very much,
> Regards,
> Luigi.

Params not initialized when starting sequencer

Ok, here is the complete code to reproduce the problem. Load parameter_test.msl which includes functions.msl. From the screenshot you see the variables containing 
garbage, and you also see that from the ODB screenshot. For completeness, I added Sequencer.json which contains the whole sequencer tree.

The interesting thing is that this works sometimes, and sometimes not. I'm not sure if this in the GUI or in the sequencer program, so we have to sort out who can 
fix it ;-)

Best,
Stefan

Attachment 1: param_test.msl

INCLUDE functions

PARAM lv_start, "Start of LV", 1.8
PARAM lv_stop, "Stop of LV", 2.1
PARAM lv_step, "Step of LV", 0.02

n_iterations = (($lv_stop - $lv_start)/$lv_step)

MSG "Parameters:"
MSG $lv_start
MSG $lv_stop
MSG $lv_step
MSG $n_iterations

MSG "Start of looping"

LOOP n, $n_iterations
   lv_now = $lv_start + $n * $lv_step
   MSG $lv_now
   WAIT SECONDS, 1
ENDLOOP

Attachment 2: functions.msl

SUBROUTINE sub1
   WAIT seconds, 1
ENDSUBROUTINE

SUBROUTINE sub2
   WAIT seconds, 1
ENDSUBROUTINE

SUBROUTINE sub3
   WAIT seconds, 1
ENDSUBROUTINE

SUBROUTINE sub4
   WAIT seconds, 1
ENDSUBROUTINE

SUBROUTINE sub5
   WAIT seconds, 1
ENDSUBROUTINE

SUBROUTINE sub6
   WAIT seconds, 1
ENDSUBROUTINE

Attachment 3: Sequencer.json

{
   "/MIDAS version": "2.1",
   "/filename": "Sequencer.json",
   "/ODB path": "/Sequencer",
   "State": {
      "New File/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "New File": false,
      "Path/key": {
         "type": 12,
         "item_size": 256,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Path": "",
      "Filename/key": {
         "type": 12,
         "item_size": 256,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Filename": "param_test.msl",
      "SFilename/key": {
         "type": 12,
         "item_size": 256,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "SFilename": "/Users/ritt/online/userfiles/sequencer/param_test.msl",
      "Next Filename/key": {
         "type": 12,
         "num_values": 10,
         "item_size": 256,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Next Filename": [
         "",
         "",
         "",
         "",
         "",
         "",
         "",
         "",
         "",
         ""
      ],
      "Error/key": {
         "type": 12,
         "item_size": 256,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Error": "",
      "Error line/key": {
         "type": 7,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Error line": 0,
      "SError line/key": {
         "type": 7,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "SError line": 0,
      "Message/key": {
         "type": 12,
         "item_size": 256,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Message": "",
      "Message Wait/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Message Wait": false,
      "Running/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Running": true,
      "Finished/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Finished": false,
      "Paused/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Paused": false,
      "Debug/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Debug": false,
      "Current line number/key": {
         "type": 7,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Current line number": 46,
      "SCurrent line number/key": {
         "type": 7,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "SCurrent line number": 20,
      "Follow Libraries/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Follow Libraries": true,
      "Stop after run/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Stop after run": false,
      "Transition request/key": {
         "type": 8,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Transition request": false,
      "Loop start line/key": {
         "type": 7,
         "num_values": 10,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Loop start line": [
         43,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0
      ],
      "SLoop start line/key": {
         "type": 7,
         "num_values": 10,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "SLoop start line": [
         17,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0
      ],
      "Loop end line/key": {
         "type": 7,
         "num_values": 10,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Loop end line": [
         47,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0
      ],
      "SLoop end line/key": {
         "type": 7,
         "num_values": 10,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "SLoop end line": [
         21,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0
      ],
      "Loop counter/key": {
         "type": 7,
         "num_values": 10,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Loop counter": [
         6,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0
      ],
      "Loop n/key": {
         "type": 7,
         "num_values": 10,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Loop n": [
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0
      ],
      "Subdir/key": {
         "type": 12,
         "item_size": 256,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Subdir": "",
      "Subdir end line/key": {
         "type": 7,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Subdir end line": 0,
      "Subdir not notify/key": {
         "type": 7,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "Subdir not notify": 0,
      "If index/key": {
         "type": 7,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "If index": 0,
      "If line/key": {
         "type": 7,
         "num_values": 10,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "If line": [
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0,
         0
      ],
      "If else line/key": {
         "type": 7,
         "num_values": 10,
         "access_mode": 7,
         "last_written": 1714720819
      },
      "If else line": [
         0,
         0,
         0,
         0,
         0,

... 379 more lines ...

Attachment 4: Screenshot_2024-05-03_at_09.19.29.png

Attachment 5: Screenshot_2024-05-03_at_09.20.47.png

Params not initialized when starting sequencer

It is pretty much the same as Stefan, I attach here the screenshots. Also in my case it works sometimes, and sometimes partially (one or 2 params, like in 
attachment 3).

> Could you please export and send me the /Sequencer ODB tree (or just /Sequencer/Param and /Sequencer/Variables) in both cases while the sequence is running. 
> 
> thanks,
> Zaher
> 
> 
> > Good afternoon,
> > 
> > After updating Midas to the latest develop commit 
> > (0f5436d901a1dfaf6da2b94e2d87f870e3611cf1) we found out a bug when starting 
> > sequencer. If we have a simple loop from start value to stop value and step 
> > size, just printing the value at each iteration, we see everything good (see 
> > first attachment). Then we included another script though, which contains 
> > several subroutines we defined for our detector, and we try to run the same 
> > script. Unfortunately after this the parameters seem uninitialized, and the 
> > value at each loop does not make sense (see second attachment). Also, sometimes 
> > when pressing run the set parameter window would pop-up, but sometimes not.
> > 
> > The script is this one:
> > 
> > >>>
> > COMMENT Test script to check for a specific bug
> > 
> > INCLUDE global_basic_functions
> > 
> > #CALL setup_paths
> > #CALL generate_DUT_params
> > 
> > PARAM lv_start, "Start of LV", 1.8
> > PARAM lv_stop, "Stop of LV", 2.1
> > PARAM lv_step, "Step of LV", 0.02
> > 
> > n_iterations = (($lv_stop - $lv_start)/$lv_step)
> > 
> > MSG "Parameters:"
> > MSG $lv_start
> > MSG $lv_stop
> > MSG $lv_step
> > MSG $n_iterations
> > 
> > MSG "Start of looping"
> > 
> > LOOP n, $n_iterations
> >    lv_now = $lv_start + $n * $lv_step
> >    MSG $lv_now
> >    WAIT SECONDS, 1
> > ENDLOOP
> > <<<
> > 
> > and the only difference comes from commenting the line:
> > 
> > >>>
> > INCLUDE global_basic_functions
> > <<<
> > 
> > as global_basic_functions is defined as a LIBRARY and it includes 75 (!) 
> > subroutines...
> > 
> > Is it possible that when loading a large script it messes up the loading of 
> > parameters?
> > 
> > Thank you very much,
> > Regards,
> > Luigi.

Attachment 1: seq1.PNG

Attachment 2: seq2.PNG

Attachment 3: seq3.PNG

Params not initialized when starting sequencer

I have been able to reproduce the problem only once. From what I see, it seems that the Variables ODB tree is not initialized properly from the Param tree. Below are the messages from the failed run compared to a successful one. As far as I could see, the javascript code does not change anything in the Variables ODB tree (only monitors it). The actual changes are done by the sequencer program, or am I wrong?

Failed run:
16:14:25.849 2024/05/03 [Sequencer,INFO]  + 3 * 
16:14:24.722 2024/05/03 [Sequencer,INFO]  + 2 * 
16:14:23.594 2024/05/03 [Sequencer,INFO]  + 1 * 
16:14:23.592 2024/05/03 [Sequencer,INFO] Start of looping
16:14:23.591 2024/05/03 [Sequencer,INFO] (( - )/)
16:14:23.591 2024/05/03 [Sequencer,INFO] 
16:14:23.590 2024/05/03 [Sequencer,INFO] 
16:14:23.590 2024/05/03 [Sequencer,INFO] 
16:14:23.589 2024/05/03 [Sequencer,INFO] Parameters:
16:14:23.562 2024/05/03 [Sequencer,TALK] Sequencer started with script "testpars.msl".


Successful run:
16:15:37.472 2024/05/03 [Sequencer,INFO] 1.820000
16:15:37.471 2024/05/03 [Sequencer,INFO] Start of looping
16:15:37.471 2024/05/03 [Sequencer,INFO] 15
16:15:37.470 2024/05/03 [Sequencer,INFO] 0.020000
16:15:37.470 2024/05/03 [Sequencer,INFO] 2.100000
16:15:37.469 2024/05/03 [Sequencer,INFO] 1.800000
16:15:37.469 2024/05/03 [Sequencer,INFO] Parameters:
16:15:37.450 2024/05/03 [Sequencer,TALK] Sequencer started with script "testpars.msl".

Params not initialized when starting sequencer

Ahh, that rings a bell:

1) JS opens start dialog box
2) User enters parameters and presses start
3) JS writes parameters
4) JS starts sequencer
5) Sequencer copies parameters to variables

Now how do you handle 3) and 4). Just issue two mjsonrpc commands together? What then could happen is that 4) is executed before 3) and we get the garbage.
You have to do 3) and WAIT for the return ("then" in the JS promise), and only then issue 4) from there.

Stefan

Params not initialized when starting sequencer

Thanks for the hint Stefan. I pushed a possible fix but I cannot test it since I cannot reproduce the issue.

> Ahh, that rings a bell:
> 
> 1) JS opens start dialog box
> 2) User enters parameters and presses start
> 3) JS writes parameters
> 4) JS starts sequencer
> 5) Sequencer copies parameters to variables
> 
> Now how do you handle 3) and 4). Just issue two mjsonrpc commands together? What then could happen is that 4) is executed before 3) and we get the garbage.
> You have to do 3) and WAIT for the return ("then" in the JS promise), and only then issue 4) from there.
> 
> Stefan

Params not initialized when starting sequencer

Seems to me like the problem happens less frequently, but I still see it (1 out of 5 or so). The fact that /Sequencer/Params/Value is empty tells me that the GUI 
has the problem and not the sequencer side.

Stefan

Attachment 1: Screenshot_2024-05-03_at_18.19.52.png

Params not initialized when starting sequencer

I think that I finally managed to fix the problem. The default values of the parameters are now written first in one go, then the sequencer waits for confirmation that everything is completed before proceeding. Please test and let me know if there are still any issues.

Zaher

Params not initialized when starting sequencer

[quote="Zaher Salman"]I think that I finally managed to fix the problem. The default values of the parameters are now written first in one go, then the sequencer waits for confirmation that everything is completed before proceeding. Please test and let me know if there are still any issues. Zaher [/quote]

Params not initialized when starting sequencer

Zaher Salman wrote:

Hi Zaher,

It seems fixed to me as well! Thanks a lot!

Luigi.

Params not initialized when starting sequencer

Hi all,
On develop, the issue seems to be still there and is not fixed.
The parameters are currently "never" correctly initialized, only as "empty". Tried several times.
Thomas

Params not initialized when starting sequencer

I traced the problem to a mjsonrpc_db_ls call where I read /Sequencer/Param... . It seems that this sometimes returns a status 312 (DB_NO_KEY) although I am sure all keys are there in the ODB.
I am still trying to solve this but I may need some help on the mjsonrpc.cxx code.

Zaher

Thomas Senger wrote:

Hi all,
On develop, the issue seems to be still there and is not fixed.
The parameters are currently "never" correctly initialized, only as "empty". Tried several times.
Thomas

Params not initialized when starting sequencer

Hi Thomas,
I have a fix for the issue and I would be happy with testers if you are willing. Simply "git checkout newfeature_ZS" and give it a go. No need to recompile anything.

A change in /Sequencer/Param triggers a save of the values which is then used to produce the parameter dialog. This allows us to bypass the slow response in mjsonrpc calls just before the dialog.

Zaher

Thomas Senger wrote:

Hi all,
On develop, the issue seems to be still there and is not fixed.
The parameters are currently "never" correctly initialized, only as "empty". Tried several times.
Thomas

Params not initialized when starting sequencer

Hi Zaher,
thanks for your help.
I just tried the bug fix, but it still seems not to work properly.
It seems that if the script is short, it will work, but if many SUBROUTINES are integrated, it does not work and the parameter are initialized empty.
Best regards,
Thomas

Params not initialized when starting sequencer

The issue with the parameters should be fixed now. Please test and let me know if it still happens.

Thomas Senger wrote:

Params not initialized when starting sequencer

I think I have had similar issues in a custom page, where I wrote values to the ODB and they were not ready when I needed them. If you found a fix to such race conditions, could you maybe share how to properly treat this issue? If the solution reliably works, we could also consider including it in the documentation (midaswiki or example.html).

Zaher Salman wrote:

The issue with the parameters should be fixed now. Please test and let me know if it still happens.

Params not initialized when starting sequencer

The problem here was that the JS code did not wait to msequencer to finish preparing the "/Sequencer/Param" in the ODB, so I had to change to code to wait for "/Sequencer/Command/Load new file" to be false before proceeding.

As for your problem I recommend that you handle in the following way:

mjsonrpc_db_paste(paths,values).then(function (rpc) {
if (rpc.result.status.every(status => status === 1) {
// do something
} else {
// failed to set values, do something else
}
}).catch(function (error) {
console.error(error);
});

alternatively (for a single ODB) you can use the checkODBValue() function in sequencer.js. This function monitors a specific ODB path until it reaches a specific value and then calls funcCall with args.

var NcheckValue = 0;
// What for ODB in path to have value
// If value is not reached, give up after 10s
function checkODBValue(path,value,funcCall,args) {
/* Arguments:
path - ODB path to monitor for value
value - the value to be reached and return success
funcCall - function name to call when value is reached
args - argument to pass to funcCall
*/
// Call the mjsonrpc_db_get_values function
mjsonrpc_db_get_values([path]).then(function(rpc) {
if (rpc.result.status[0] === 1 && rpc.result.data[0] !== value) {
console.log("Value not reached yet", NcheckValue);
NcheckValue++;
if (NcheckValue < 100) {
// Wait 0.1 second and then call checkODBValue again
// Time out after 10 s
setTimeout(() => {
checkODBValue(path,value,funcCall,args);
}, 100);
}
} else {
if (funcCall) funcCall(args);
console.log("Value reached, proceeding...");
// reset counter
NcheckValue = 0;
}
}).catch(function(error) {
console.error(error);
});
}

Lukas Gerritzen wrote:

Zaher Salman wrote:

The issue with the parameters should be fixed now. Please test and let me know if it still happens.

Goto page Previous 1, 2, 3 ... 88, 89, 90 ... 153, 154, 155 Next ELOG V3.1.4-2e1708b5