> > I would not say this is expected behavior.
> >
> > It seems that you are executing on a somewhat slower system (tsc clock 
> > seems to be 100/us = 0.1 GHz) and that, even with only 5
> lines logged before and after,  the logging output is causing so much slow 
> down of the PMD that it continues to cause iterations using
> excessive cycles (362000 = 3.62 ms!) due to logging.
> The system is slower than usual, but not so much.
> This behaviour captured on ARMv8. The TSC frequency on ARM is usually around 
> 100MHz
> without using PMU which is not available from userspace by default.
> Meantime, CPU frequency is 2GHz.

On my x86_64 server (2.4 GHz) I could reproduce the periodic logging if I go 
down with the us_thr to values as low as 50 us under high PMD load. But it 
always stops when I increase the threshold to a value higher than 80 us. It 
seems you ARM system is much slower when logging to file. The threshold that 
should be reasonably applied may depend on the system under test.

> >
> > The actual iteration with logging is not flagged as suspicious, but the 
> > subsequent iteration gets the hit of the massive cycles that have
> passed on the TSC clock. The "phantom" duration of 0 us shown is probably a 
> side effect of this.
> I guess, you just have some bug in your calculation of execution time.
> Possibly you're mixing up the TSC and CPU frequencies.
> Zero ms duration is normal for printing so small amount of data.

It was actually a bug in the code: The iteration logged as suspicious was the 
one directly after the actually suspicious iteration. That bug is fixed in v11 
I just sent out.

BR, Jan
dev mailing list

Reply via email to