[asterisk-dev] Digium TE820 on BSD: bunch of missed interrupts

[Łukasz Wójcik]

W dniu 2014-05-16 20:32, Łukasz Wójcik pisze:
> On 05/15/2014 07:52, Russ Meyerriecks wrote:
>> On Wed, May 14, 2014 at 1:40 PM, Łukasz Wójcik <lukasz.wojcik at zoho.com
>> <mailto:lukasz.wojcik at zoho.com>> wrote:
>>
>>     That's what I just did. It seems that irq handling routine takes
>>     260-280ms during span setup. My measurements indicate that the most
>>     time is being spent in '__t4_set_timing_source_auto()__'
>>
>>
>> This is curious. There is no blocking in that function and it's just a
>> small number of bit checks and two gpio writes.
>>
>>     (..)
>>     Missed interrupt. Expected ident of 97 and got ident of 111
>>     <maaaaaaaaaaaaaany similar as above, differing with idents>
>>     (..)
>>
>>
>> It might be helpful to see the full output of the kernel log while the
>> wct4xxp module is starting up.
>>
>
> Hello again, Russ
>
> Please see the log attached.
>
> Log lines starting with 'TICKS' is my addition. The whole interrupt
> handler was divided into 11 points, at which number of 'ticks' is taken.
> Clock ticks 1000x per second, so a single tick means 1ms.
> The line is intended to show CPU ticks at those sampling points, how
> many ticks it took to handle interrupt. 'samples taken' shows how many
> of 11 sampling points were actually reached (it may be less than 11 if
> certain code path was taken). All irq handler runs that take very long
> to finish, seem to spend most time between sampling points:
> 5-6 and 9-10.
>
> Sampling point 5. is located just before call to t4_prep_gen2().
> Sampling point 6. is located just after call to __handle_leds().
>
> (...)
> 4248 //5
> 4249                 } else {
> 4250                         t4_prep_gen2(wc);
> 4251                 }
> 4252
> 4253 #endif
> 4254                 t4_do_counters(wc);
> 4255                 spin_lock(&wc->reglock);
> 4256                 __handle_leds(wc);
> 4257                 spin_unlock(&wc->reglock);
> 4258
> 4259         }
> 4260 //6
> (...)
>
> Sampling point 9. and 10. :
> (...)
> 4304 //9
> 4306         if (unlikely(test_bit(T4_CHECK_TIMING, &wc->checkflag))) {
> 4307                 __t4_set_timing_source_auto(wc);
> 4308         }
> 4309
> 4310 //10
> (...)
>
> NOTE that line numbers won't match your codebase, but given code blocks
> should be easy to locate in irq handler routine (_t4_interrupt_gen2()).

Oh, and lines starting with "dahdi_iface(dahdi at TE8/X/Y/Z):" are FreeBSD 
specific.

Thanks again,
-ŁW