Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use logs as part of the validation #1192

Closed
tvami opened this issue Aug 18, 2023 · 3 comments · Fixed by #1198
Closed

Use logs as part of the validation #1192

tvami opened this issue Aug 18, 2023 · 3 comments · Fixed by #1198
Assignees
Milestone

Comments

@tvami
Copy link
Member

tvami commented Aug 18, 2023

Is your feature request related to a problem? Please describe.

Connected to #1191, the validation config shows a lot of warnings, which triggered the discussion on what's the best way to notice these kind of changes

Describe the solution you'd like

The logs of the validation could be compared to the output logs before the PR, if the character count is increased significantly that could be a sign of new warning msgs.

@bryngemark
Copy link
Contributor

This was discussed in the sw dev meeting today, and we concluded that even storing the logs in the repo just as we do with the "gold" histograms, and running a simple diff as part of the automated validation suite, would suffice (and perhaps be helpful). @tomeichlersmith seemed to have a clear idea of how to set this up -- please Tom, if you prefer for someone else to do it just shout.

@tomeichlersmith
Copy link
Member

Unfortunately, a textual diff is going to be a bit more complicated since there are some timestamps printed to the terminal.
Doing two runs of the inclusive validation sample produced slightly different logs. This appears to be a result from a few processors using the ldmx_log within the configure function which is currently called before the log is set up. This leaves us with a few options:

  1. Patch up places where ldmx_log is used in configure (probably moving them to onProcessStart).
    • Down side: officially limits the tests from running anything that includes a timestamp.
  2. Develop some funky diff nonsense to ignore timestamps.
    • Down side: pre-processing log files may lead to ignoring certain errors
  3. Don't do a full textual diff and just look at character/word count like @tvami has suggested
    • Down side: no information about what changed if the test fails
3c3
< [2023-08-23 15:25:45.065679] [0x00007fbbeb804bc0] [info]    ElectronCounter is using parameters:  
---
> [2023-08-23 15:26:17.252824] [0x00007f1a83118bc0] [info]    ElectronCounter is using parameters:  
15,18c15,18
< [2023-08-23 15:25:45.087729] [0x00007fbbeb804bc0] [info]    In TrigScintClusterDQM::configure, got parameters TriggerPad1Clusters, pad = pad1, pass = 
< [2023-08-23 15:25:45.087737] [0x00007fbbeb804bc0] [info]    In TrigScintClusterDQM::configure, got parameters TriggerPad2Clusters, pad = pad2, pass = 
< [2023-08-23 15:25:45.087743] [0x00007fbbeb804bc0] [info]    In TrigScintClusterDQM::configure, got parameters TriggerPad3Clusters, pad = pad3, pass = 
< [2023-08-23 15:25:45.087764] [0x00007fbbeb804bc0] [info]    In TrigScintTrackDQM::configure, got parameters TriggerPadTracks and 
---
> [2023-08-23 15:26:17.260153] [0x00007f1a83118bc0] [info]    In TrigScintClusterDQM::configure, got parameters TriggerPad1Clusters, pad = pad1, pass = 
> [2023-08-23 15:26:17.260160] [0x00007f1a83118bc0] [info]    In TrigScintClusterDQM::configure, got parameters TriggerPad2Clusters, pad = pad2, pass = 
> [2023-08-23 15:26:17.260166] [0x00007f1a83118bc0] [info]    In TrigScintClusterDQM::configure, got parameters TriggerPad3Clusters, pad = pad3, pass = 
> [2023-08-23 15:26:17.260175] [0x00007f1a83118bc0] [info]    In TrigScintTrackDQM::configure, got parameters TriggerPadTracks and 

Procedure

cd ldmx-sw
. scripts/ldmx-env.sh
ldmx clean src
ldmx cmake -B build -S .
cd build
ldmx make -j4 install
cd ../.github/validation_samples/inclusive
ldmx setenv LDMX_RUN_NUMBER=1
ldmx setenv LDMX_NUM_EVENTS=10
ldmx fire config.py &> first.log
ldmx fire config.py &> secon.log
diff first.log secon.log

@bryngemark
Copy link
Contributor

thanks for looking into the options, tom. since I wrote the configure printouts I can say that I'm not invested in having them print out from configure() but I do want them printed somewhere until there is a bullet proof method of making sure that we never end up passing a setting using a non-existing parameter name in python that gets ignored by ldmx-sw down the line.

about the character count downside, if storing the "gold" logs per se isn't an issue (no space constraints), we could in principle still keep them, run a character count that accepts differences within some tolerance (if time stamps etc don't have fixed lengths), and both sound an alarm and keep the new log as an artifact (along with failed histograms?) in case there is an actual difference. in case there is agreement then we just happily state that and move on. would that work?

@tomeichlersmith tomeichlersmith linked a pull request Sep 12, 2023 that will close this issue
3 tasks
@tomeichlersmith tomeichlersmith added this to the v3.3.0 milestone Sep 13, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants