What's going on with lhef_8?

[kilian]

This test takes ages to complete. On my laptop

real    10m57.405s
user    10m57.505s
sys     0m0.144s

It spends its time handling this event transform:

========================================================================
 Event transform: shower
------------------------------------------------------------------------
   Associated process: 'lhef_8_p1'
   TAO random-number generator:
     seed  = 262150
     calls = 1
   Number of tries = 0
------------------------------------------------------------------------
 Shower settings:
------------------------------------------------------------------------
 Master switches:
   ps_isr_active                =  T
   ps_fsr_active                =  T
   muli_active                  =  F
 General settings:
   shower_method                =  WHIZARD
   shower_verbose               =  F
   ps_mass_cutoff               =  1.000000000000E+00
   ps_max_n_flavors             =  5
 ISR settings:
   ps_isr_pt_ordered            =  F
   ps_isr_lambda                =  2.900000000000E-01
   ps_isr_alpha_s_running       =  T
   ps_isr_primordial_kt_width   =  0.000000000000E+00
   ps_isr_primordial_kt_cutoff  =  5.000000000000E+00
   ps_isr_z_cutoff              =  9.990000000000E-01
   ps_isr_minenergy             =  1.000000000000E+00
   ps_isr_tscalefactor          =  1.000000000000E+00
 FSR settings:
   ps_fsr_lambda                =  2.900000000000E-01
   ps_fsr_alpha_s_running       =  T
 Hadronization settings:
   hadronization_active         =  F
 Matching Settings:
   mlm_matching                 =  F
   ckkw_matching                =  F
 PYTHIA6 specific settings:
   ps_PYTHIA_PYGIVE             = ''

Compiler settings: nagfor -C=all -gline -nan -f2003 Yes, this is slow settings, but well ... it should be possible to run the test suite.

[Bijan Chokoufe Nejad]

Well, we noticed this as well. With gfortran -O2 I get it done at least in 3m6.715s. It is spending its time in the analytic ISR shower, which always has been very slow. When you run whizard with --debug shower you see that it is mostly in shower_execute_next_isr_branching or as you see with --debug2 more specifically in integral_over_z_part_isr.

We are not sure, however, if this was always that slow or what could have changed to produce this issue. Can you say if a certain older revision was significantly faster on this test?

[kilian]

It definitely was faster some time ago. I don't think the whole test suite took longer than 10min with NAG, or 3-5min with gfortran. But I didn't check.

The other issue is that one cannot interrupt the program in this state, one has to kill -9 it. There should be breakpoints in the loop.

If this is not trivial to solve, I'd recommend moving this test to the weekly test suite. Otherwise, it's becoming a real blocker.

[Bijan Chokoufe Nejad]

I readded the breakpoints already. I will check. Maybe I can find out what/if something is going wrong. Moving this to weekly should be the last resort move when we understood why it is taking longer now.

[Bijan Chokoufe Nejad]

OK, I can confirm that on r6646 the test took 3.48s.

[Bijan Chokoufe Nejad]

Same short time with r6896.

[Bijan Chokoufe Nejad]

Some more observations:

• There seems to be a factor of ~3 and a factor of ~20 slowdown.
• In r6963 the test took about 62s, so about three times faster than now and about 20 times slower than r6896.
• Comparing the callgraph of the current trunk and r6646, I see that
  • the old apply_shower_particle was only called once while the analogue generate_emissions is now called three times.
  • same rough factor of three for integral_over_z_part_isr
  • In the current trunk d_alpha_s_fsr is called 3600 times the amount of d_alpha_s_isr in r6646. The process has in principle FSR as well as ISR.

I will try to locate the big factor of 20 between r6963 and r6896 first.

[Juergen Reuter]

We found the culprit, expect a workaround later tonight.

[Juergen Reuter]

Fixed in r7011: now ?ps_isr_only_onshell_emitted_partons = true is explicitly set in the lhef_8.sin SINDARIN file. The default (as in PYTHIA's MSTP(63) parameter) is false, such that off-shell ISR partons can also initiate further (final state) showering. This was not the case before the matching refactoring by BACN in r6956, where this parameter was false as default in rt_data, but the shower_t type had it's "own" default set to true. Now, again, this is explicitly set, and the test is back to light speed. (of course, at some point, we might want to track this down, but shower 'tuning' (read: profiling) is on our list anyhow. Closing this one.