lkml.org 
[lkml]   [2014]   [Feb]   [20]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: locking changes in tty broke low latency feature
    On 02/19/2014 09:55 PM, Peter Hurley wrote:
    > On 02/19/2014 06:06 PM, Hal Murray wrote:
    >>> Can you give me an idea of your device's average and minimum required
    >>> latency (please be specific)? Is your target arch x86 [so I can evaluate the
    >>> the impact of bus-locked instructions relative to your expected]?
    >>
    >> The code I'm familiar with is ntpd and gpsd. They run on almost any hardware
    >> or OS and talk to a wide collection of devices.
    >>
    >> There is no hard requirement for latency. They just work better with lower
    >> latency. The lower the better.
    >>
    >> People gripe about the latency due to USB polling which is about a ms.
    >
    > Have you tried 3.12+ without low_latency? I ripped out a lot of locks
    > from 3.12+ so it's possible it already meets your requirements.

    Using Alan's idea to mock up a latency test, I threw together a test jig
    using two computers running 3.14-rc1 and my fwserial driver (modified to
    not aggregrate writes) in raw mode where the target does this:

    while (1) {
    read 64 bytes
    compare to pattern
    write 1 byte response
    }

    and the sender does this:

    for (i = 0; i < 2000; i++) {
    write 64-byte pattern
    read 1 byte response
    }

    Sender completes 2000 loops in 160ms total run time;
    that's 80us average per complete round-trip.

    Here's a snapshot of a function trace for 1 complete round trip at the target:

    <idle>-0 [007] d.h1 4856.935561: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000010 AR_req
    <idle>-0 [007] ..s1 4856.935566: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AR spd 2 tl 2a, ffc1 -> ffc0, ack_complete, BW req, 800000000004 40,0
    <idle>-0 [007] ..s1 4856.935567: tty_flip_buffer_push <-fwtty_port_handler
    kworker/7:0-6872 [007] .... 4856.935571: flush_to_ldisc <-process_one_work
    tty-latency-tes-6891 [003] .... 4856.935578: n_tty_write <-tty_write
    <idle>-0 [003] d.h1 4856.935591: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000001 AT_req
    <idle>-0 [003] ..s1 4856.935594: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AT spd 2 tl 12, ffc0 -> ffc1, ack_complete, BW req, 800000000004 1,0

    The same snapshot explained:

    The firewire controller IRQ for received packet in rx dma fifo:

    <idle>-0 [007] d.h1 4856.935561: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000010 AR_req

    The firewire-ohci driver rx fifo tasklet running:

    <idle>-0 [007] ..s1 4856.935566: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AR spd 2 tl 2a, ffc1 -> ffc0, ack_complete, BW req, 800000000004 40,0

    The fwserial driver schdeduling the rx data:

    <idle>-0 [007] ..s1 4856.935567: tty_flip_buffer_push <-fwtty_port_handler

    The tty buffer input worker running:

    kworker/7:0-6872 [007] .... 4856.935571: flush_to_ldisc <-process_one_work

    The test application having received the data, compared it,
    and writing the 1-byte response:

    tty-latency-tes-6891 [003] .... 4856.935578: n_tty_write <-tty_write

    The firewire controller IRQ for running the tx dma fifo:

    <idle>-0 [003] d.h1 4856.935591: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000001 AT_req

    The firewire-ohci driver tx fifo tasklet acknowledging the sender
    of the 64-byte packet has received the 1-byte response:

    <idle>-0 [003] ..s1 4856.935594: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AT spd 2 tl 12, ffc0 -> ffc1, ack_complete, BW req, 800000000004 1,0


    ... trace continued for another 4x 64-byte reads and 1 byte responses:

    <idle>-0 [007] d.h1 4856.935646: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000010 AR_req
    <idle>-0 [007] ..s1 4856.935650: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AR spd 2 tl 2b, ffc1 -> ffc0, ack_complete, BW req, 800000000004 40,0
    <idle>-0 [007] ..s1 4856.935651: tty_flip_buffer_push <-fwtty_port_handler
    kworker/7:0-6872 [007] .... 4856.935655: flush_to_ldisc <-process_one_work
    tty-latency-tes-6891 [003] .... 4856.935662: n_tty_write <-tty_write
    <idle>-0 [003] d.h1 4856.935674: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000001 AT_req
    <idle>-0 [003] ..s1 4856.935678: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AT spd 2 tl 13, ffc0 -> ffc1, ack_complete, BW req, 800000000004 1,0
    <idle>-0 [007] d.h1 4856.935729: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000010 AR_req
    <idle>-0 [007] ..s1 4856.935733: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AR spd 2 tl 2c, ffc1 -> ffc0, ack_complete, BW req, 800000000004 40,0
    <idle>-0 [007] ..s1 4856.935734: tty_flip_buffer_push <-fwtty_port_handler
    kworker/7:0-6872 [007] .... 4856.935738: flush_to_ldisc <-process_one_work
    tty-latency-tes-6891 [003] .... 4856.935746: n_tty_write <-tty_write
    <idle>-0 [003] d.h1 4856.935758: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000001 AT_req
    <idle>-0 [003] ..s1 4856.935762: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AT spd 2 tl 14, ffc0 -> ffc1, ack_complete, BW req, 800000000004 1,0
    <idle>-0 [007] d.h1 4856.935812: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000010 AR_req
    <idle>-0 [007] ..s1 4856.935816: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AR spd 2 tl 2d, ffc1 -> ffc0, ack_complete, BW req, 800000000004 40,0
    <idle>-0 [007] ..s1 4856.935817: tty_flip_buffer_push <-fwtty_port_handler
    kworker/7:0-6872 [007] .... 4856.935821: flush_to_ldisc <-process_one_work
    tty-latency-tes-6891 [003] .... 4856.935828: n_tty_write <-tty_write
    <idle>-0 [003] d.h1 4856.935844: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000001 AT_req
    <idle>-0 [003] ..s1 4856.935847: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AT spd 2 tl 15, ffc0 -> ffc1, ack_complete, BW req, 800000000004 1,0
    <idle>-0 [007] d.h1 4856.935895: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000010 AR_req
    <idle>-0 [007] ..s1 4856.935899: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AR spd 2 tl 2e, ffc1 -> ffc0, ack_complete, BW req, 800000000004 40,0
    <idle>-0 [007] ..s1 4856.935900: tty_flip_buffer_push <-fwtty_port_handler
    kworker/7:0-6872 [007] .... 4856.935904: flush_to_ldisc <-process_one_work
    tty-latency-tes-6891 [003] .... 4856.935911: n_tty_write <-tty_write
    <idle>-0 [003] d.h1 4856.935923: irq_handler: firewire_ohci 0000:07:06.0: IRQ 00000001 AT_req
    <idle>-0 [003] ..s1 4856.935927: log_ar_at_event.isra.33: firewire_ohci 0000:07:06.0: AT spd 2 tl 16, ffc0 -> ffc1, ack_complete, BW req, 800000000004 1,0


    I think this shows that low_latency is unnecessary and should
    just be removed/ignored by the tty core.

    Let me know if you want my test jig (or fwserial patch). The test
    was run on a 10-year old Vaio single-core laptop as the sender and
    6-year old dual socket xeon workstation (so nothing super tricked
    out for this test).


    Regards,
    Peter Hurley


    \
     
     \ /
      Last update: 2014-02-20 19:41    [W:2.577 / U:0.004 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site