On 16.03.2013 18:39, Alan Stern wrote:

On Sat, 16 Mar 2013, Soeren Moch wrote:

quoted

I implemented the counter. The max value is sampled at the beginning of
end_free_itds(), the current counter value is sampled at the end of this
function. Counter values w/o a max number are from the error path in
itd_urb_transaction().
The number of allocated iTDs can grow to higher values (why?), but
normally the iTDs are freed during normal operation. Due to some reason
the number of iTDs suddenly increases until coherent pool exhaustion.
There is no permanent memory leak, all iTDs are released when the user
application ends. But imho several thousands of iTDs cannot be the
intended behavior...

No, it's not.  Here's how it's supposed to work:

Each ehci_iso_stream structure corresponds to a single isochronous
endpoint.  The structure has a free list of iTDs that aren't currently
in use; when an URB is submitted, its iTDs are taken from the start of
this free list if possible.  Otherwise new iTDs are allocated from the
DMA pool.

iTDs on the free list aren't always available.  This is because the
hardware can continue to access an iTD for up to 1 ms after the iTD has
completed.  itd->frame stores the frame number (one frame per ms) for
when the iTD completes, and ehci->now_frame contains a best estimate of
the current frame number.  This explains the logic in
itd_urb_transaction().  Near the end of itd_complete() you can see
where a completed iTD gets added back to the end of the free list.

At the very end of itd_complete() is a section of code that takes the
entries on the iso_stream's free list and moves them to a global free
list (ehci->cached_itd_list).  This happens only when the endpoint is
no longer in use, i.e., no iTDs are queued for it.  The end_free_itds()
routine in ehci_timer.c takes iTDs from this global list and releases
them back to the DMA pool.  The routine doesn't run until at least 1 ms
after start_free_itds() is called, to wait for the hardware to stop
accessing the iTDs on the list.

The idea is that during normal use we will quickly reach a steady
state, where an endpoint always has about N URBs queued for it, each
URB uses about M iTDs, and there are one or two URB's worth of unused
iTDs.  Thus there will be N*M iTDs in use plus maybe another 2*M iTDs
on the iso_stream's free list.  Once we reach this point, every new URB
should be able to get the iTDs it needs from the free list (assuming a
new URB is submitted every time an URB completes).  When the URBs stop
being submitted, the pipeline will empty out and after a couple more
milliseconds, all (N+2)*M iTDs should be released back to the pool.

In your case the situation is complicated by the fact that you're using
two devices, each of which has up to four isochronous endpoints.  This
makes it harder to see what's going on.  Probably not all of the
endpoints were being used for data transfers.  But even if they were,
there should not have been more then 800 iTDs allocated at any time
(figure that N is around 5 and M is 9).  You could simplify the testing
by using only one device -- it might not exhaust the pool but your iTD
counter would still indicate if something wasn't right.

I'm not sure how to figure out what's causing the problem.  Maybe you
can think of a good way to see where the actual operation differs from
the description above.  Perhaps start by keeping track of the number of
iTDs on each iso_stream's free list and the number in use by each
iso_stream.

For each device only one isochronous endpoint is used (EP IN4, 1x 940 
Bytes, Interval 1).
When the ENOMEM error occurs, a huge number of iTDs is in the free_list 
of one stream. This number is much higher than the 2*M entries, which 
should be there according to your description.

  Soeren Moch


Mar 17 17:06:49 guruvdr kernel: free iso_stream:0xd802d840
Mar 17 17:06:49 guruvdr kernel: iso_stream_init: stream:0xd802d7e0 dev:5 
ep:132 int:1 maxp:940 bw:152
Mar 17 17:06:50 guruvdr kernel: free iso_stream:0xd802d9c0
Mar 17 17:06:50 guruvdr kernel: iso_stream_init: stream:0xd802d360 dev:6 
ep:132 int:1 maxp:940 bw:152
Mar 17 17:07:09 guruvdr kernel: itd_counter:42 (max:4549)
Mar 17 17:07:09 guruvdr kernel: itd_counter:0 (max:4549)
Mar 17 17:07:10 guruvdr kernel: free iso_stream:0xd802d7e0
Mar 17 17:07:11 guruvdr kernel: iso_stream_init: stream:0xd802d7e0 dev:5 
ep:132 int:1 maxp:940 bw:152
Mar 17 17:07:11 guruvdr kernel: free iso_stream:0xd802d360
Mar 17 17:07:11 guruvdr kernel: iso_stream_init: stream:0xd802d360 dev:6 
ep:132 int:1 maxp:940 bw:152
Mar 17 17:15:13 guruvdr kernel: ERROR: 1024 KiB atomic DMA coherent pool 
is too small!
Mar 17 17:15:13 guruvdr kernel: Please increase it with coherent_pool= 
kernel parameter!
Mar 17 17:15:13 guruvdr kernel: itd_counter:6275
Mar 17 17:15:13 guruvdr kernel: stream0 num_td_list_entries:33 
num_free_list_entries:6200
Mar 17 17:15:13 guruvdr kernel: stream1 num_td_list_entries:36 
num_free_list_entries:6
Mar 17 17:15:13 guruvdr kernel: orion-ehci orion-ehci.0: can't init itds
Mar 17 17:15:13 guruvdr kernel: itd_counter:6275
Mar 17 17:15:13 guruvdr kernel: stream0 num_td_list_entries:25 
num_free_list_entries:6208
Mar 17 17:15:13 guruvdr kernel: stream1 num_td_list_entries:35 
num_free_list_entries:7
Mar 17 17:15:13 guruvdr kernel: orion-ehci orion-ehci.0: can't init itds
Mar 17 17:15:14 guruvdr kernel: itd_counter:6275
Mar 17 17:15:14 guruvdr kernel: stream0 num_td_list_entries:17 
num_free_list_entries:6216
Mar 17 17:15:14 guruvdr kernel: stream1 num_td_list_entries:35 
num_free_list_entries:7
Mar 17 17:15:14 guruvdr kernel: orion-ehci orion-ehci.0: can't init itds
Mar 17 17:15:14 guruvdr kernel: itd_counter:6275
Mar 17 17:15:14 guruvdr kernel: stream0 num_td_list_entries:9 
num_free_list_entries:6224
Mar 17 17:15:14 guruvdr kernel: stream1 num_td_list_entries:35 
num_free_list_entries:7
Mar 17 17:15:14 guruvdr kernel: orion-ehci orion-ehci.0: can't init itds
Mar 17 17:15:16 guruvdr kernel: itd_counter:6275
Mar 17 17:15:16 guruvdr kernel: stream0 num_td_list_entries:1 
num_free_list_entries:6232
Mar 17 17:15:16 guruvdr kernel: stream1 num_td_list_entries:40 
num_free_list_entries:2
Mar 17 17:15:16 guruvdr kernel: orion-ehci orion-ehci.0: can't init itds
Mar 17 17:15:16 guruvdr kernel: itd_counter:42 (max:6275)
Mar 17 17:16:31 guruvdr kernel: itd_counter:0 (max:6275)
Mar 17 17:16:32 guruvdr kernel: free iso_stream:0xd802d7e0
Mar 17 17:16:32 guruvdr kernel: iso_stream_init: stream:0xd802d6c0 dev:5 
ep:132 int:1 maxp:940 bw:152
Mar 17 17:16:36 guruvdr kernel: free iso_stream:0xd802d360
Mar 17 17:16:36 guruvdr kernel: iso_stream_init: stream:0xd802da20 dev:6 
ep:132 int:1 maxp:940 bw:152