diff mbox

usb HC busted?

Message ID 2e8829c2-850d-6bca-5f0c-58a809dc9499@linux.intel.com (mailing list archive)
State New, archived
Headers show

Commit Message

Mathias Nyman June 7, 2018, 7:40 a.m. UTC 
On 06.06.2018 19:45, Sudip Mukherjee wrote:
> Hi Andy,
> 
> And we meet again. :)
> 
> On Wed, Jun 06, 2018 at 06:36:35PM +0300, Andy Shevchenko wrote:
>> On Wed, 2018-06-06 at 17:12 +0300, Mathias Nyman wrote:
>>> On 04.06.2018 18:28, Sudip Mukherjee wrote:
>>>> On Thu, May 24, 2018 at 04:35:34PM +0300, Mathias Nyman wrote:
>>>>>
>>
>>> Odd and unlikely, but to me this looks like some issue in allocating
>>> dma memory
>>> from pool using dma_pool_zalloc()
>>>
>>> Adding people with DMA knowledge to cc, maybe someone knows what is
>>> going on.
>>>
>>> Here's the story:
>>> Sudip sees usb issues on a Intel Atom based board with 4.14.2 kernel.
>>> All tracing points to dma_pool_zalloc() returning the same dma address
>>> block on
>>> consecutive calls.
>>>
>>> In the failing case dma_pool_zalloc() is called 3 - 6us apart.
>>>
>>> <...>-26362 [002] ....  1186.756739: xhci_ring_mem_detail: MATTU
>>> xhci_segment_alloc dma @ 0x000000002d92b000
>>> <...>-26362 [002] ....  1186.756745: xhci_ring_mem_detail: MATTU
>>> xhci_segment_alloc dma @ 0x000000002d92b000
>>> <...>-26362 [002] ....  1186.756748: xhci_ring_mem_detail: MATTU
>>> xhci_segment_alloc dma @ 0x000000002d92b000
>>>
>>> dma_pool_zalloc() is called from xhci_segment_alloc() in
>>> drivers/usb/host/xhci-mem.c
>>> see:
>>> https://elixir.bootlin.com/linux/v4.14.2/source/drivers/usb/host/xhci-
>>> mem.c#L52
>>>
>>> prints above are custom traces added right after dma_pool_zalloc()
>>
>> For better understanding it would be good to have dma_pool_free() calls
>> debugged as well.
> 
> So, I am adding another trace event for dma_pool_free() and continuing
> with the test. Is there anything else that I should be adding as debug?
> 

The patch traced both dma_pool_zalloc() and dma_pool_free() calls from xhci,
no need to retry.

Sudip has a full (394M unpacked) trace at:
https://drive.google.com/open?id=1h-3r-1lfjg8oblBGkzdRIq8z3ZNgGZx-

Interesting part is:

<...>-26362 [002] ....  1186.756728: xhci_ring_mem_detail: MATTU xhci_segment_alloc dma @ 0x000000002d34d000
<...>-26362 [002] ....  1186.756735: xhci_ring_mem_detail: MATTU xhci segment alloc seg->dma @ 0x000000002d34d000
<...>-26362 [002] ....  1186.756739: xhci_ring_mem_detail: MATTU xhci_segment_alloc dma @ 0x000000002d92b000
<...>-26362 [002] ....  1186.756740: xhci_ring_mem_detail: MATTU xhci segment alloc seg->dma @ 0x000000002d92b000
<...>-26362 [002] ....  1186.756743: xhci_ring_alloc: ISOC eefa0580: enq 0x000000002d34d000(0x000000002d34d000) deq 0x000000002d34d000(0x000000002d34d000) segs 2 stream 0 free_trbs 509 bounce 17 cycle 1
<...>-26362 [002] ....  1186.756745: xhci_ring_mem_detail: MATTU xhci_segment_alloc dma @ 0x000000002d92b000
<...>-26362 [002] ....  1186.756746: xhci_ring_mem_detail: MATTU xhci segment alloc seg->dma @ 0x000000002d92b000
<...>-26362 [002] ....  1186.756748: xhci_ring_mem_detail: MATTU xhci_segment_alloc dma @ 0x000000002d92b000
<...>-26362 [002] ....  1186.756751: xhci_ring_mem_detail: MATTU xhci segment alloc seg->dma @ 0x000000002d92b000
<...>-26362 [002] ....  1186.756752: xhci_ring_alloc: ISOC f19d7c80: enq 0x000000002d92b000(0x000000002d92b000) deq 0x000000002d92b000(0x000000002d92b000) segs 2 stream 0 free_trbs 509 bounce 17 cycle 1
<...>-26362 [002] d..1  1186.756761: xhci_queue_trb: CMD: Configure Endpoint Command: ctx 000000002ce96000 slot 7 flags d:C
<...>-26362 [002] d..1  1186.756762: xhci_inc_enq: CMD ed930b80: enq 0x000000002d93adb0(0x000000002d93a000) deq 0x000000002d93ada0(0x000000002d93a000) segs 1 stream 0 free_trbs 253 bounce 0 \
cycle 1
<...>-26362 [002] ....  1186.757066: xhci_dbg_context_change: Successful Endpoint Configure command
<...>-26362 [002] ....  1186.757072: xhci_ring_free: ISOC eefd9380: enq 0x000000002c482000(0x000000002c482000) deq 0x000000002c482000(0x000000002c482000) segs 2 stream 0 free_trbs 509 bounce0 cycle 1
<...>-26362 [002] ....  1186.757075: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ ee2d23c8
<...>-26362 [002] ....  1186.757078: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ c7a93488
<...>-26362 [002] ....  1186.757080: xhci_ring_free: ISOC eef0d800: enq 0x000000002c50a000(0x000000002c50a000) deq 0x000000002c50a000(0x000000002c50a000) segs 2 stream 0 free_trbs 509 bounce0 cycle 1

What is shown is the allocation of two ISOC transfer rings, each ring has 2 segments (two dma_pool_zalloc() calls per ring)
First ring looks normal, ring1 get dma memory at 0x2d34d000 for first ring segment, and dma memory at 0x2d92b000 for second segment.

But then it gets stuck, for the whole ring2 dma_pool_zalloc() just returns the same dma address as the last segment for
ring1:0x2d92b000. Last part of trace snippet is just another ring being freed.

Full testpatch looked like this:

Comments

Sudip Mukherjee June 8, 2018, 9:07 a.m. UTC | #1 
Hi All,

On Thu, Jun 07, 2018 at 10:40:03AM +0300, Mathias Nyman wrote:
> On 06.06.2018 19:45, Sudip Mukherjee wrote:
> > Hi Andy,
> > 
> > And we meet again. :)
> > 
> > On Wed, Jun 06, 2018 at 06:36:35PM +0300, Andy Shevchenko wrote:
> > > On Wed, 2018-06-06 at 17:12 +0300, Mathias Nyman wrote:
> > > > On 04.06.2018 18:28, Sudip Mukherjee wrote:
> > > > > On Thu, May 24, 2018 at 04:35:34PM +0300, Mathias Nyman wrote:
> > > > > > 
> > > 
> > > > Odd and unlikely, but to me this looks like some issue in allocating
> > > > dma memory
> > > > from pool using dma_pool_zalloc()
> > > > 
> > > > Adding people with DMA knowledge to cc, maybe someone knows what is
> > > > going on.
> > > > 
> > > > Here's the story:
> > > > Sudip sees usb issues on a Intel Atom based board with 4.14.2 kernel.
> > > > All tracing points to dma_pool_zalloc() returning the same dma address
> > > > block on
> > > > consecutive calls.

We have started testing with v4.14.47 now and we are seeing the issue
with it also. :(

--
Regards
Sudip

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Sudip Mukherjee June 21, 2018, 12:53 a.m. UTC | #2 
Hi Mathias, Andy,

On Thu, Jun 07, 2018 at 10:40:03AM +0300, Mathias Nyman wrote:
> On 06.06.2018 19:45, Sudip Mukherjee wrote:
> > Hi Andy,
> > 
> > And we meet again. :)
> > 
> > On Wed, Jun 06, 2018 at 06:36:35PM +0300, Andy Shevchenko wrote:
> > > On Wed, 2018-06-06 at 17:12 +0300, Mathias Nyman wrote:
> > > > On 04.06.2018 18:28, Sudip Mukherjee wrote:
> > > > > On Thu, May 24, 2018 at 04:35:34PM +0300, Mathias Nyman wrote:
> > > > > > 
> > > 
> > > > Odd and unlikely, but to me this looks like some issue in allocating
> > > > dma memory
> > > > from pool using dma_pool_zalloc()
> > > > 
> > > > 
> > > > Here's the story:
> > > > Sudip sees usb issues on a Intel Atom based board with 4.14.2 kernel.
> > > > All tracing points to dma_pool_zalloc() returning the same dma address
> > > > block on
> > > > consecutive calls.
> > > > 
> > > > In the failing case dma_pool_zalloc() is called 3 - 6us apart.
> > > > 
> > > > <...>-26362 [002] ....  1186.756739: xhci_ring_mem_detail: MATTU
> > > > xhci_segment_alloc dma @ 0x000000002d92b000
> > > > <...>-26362 [002] ....  1186.756745: xhci_ring_mem_detail: MATTU
> > > > xhci_segment_alloc dma @ 0x000000002d92b000
> > > > <...>-26362 [002] ....  1186.756748: xhci_ring_mem_detail: MATTU
> > > > xhci_segment_alloc dma @ 0x000000002d92b000
> > > > 
> > > > dma_pool_zalloc() is called from xhci_segment_alloc() in
> > > > drivers/usb/host/xhci-mem.c
> > > > see:
> > > > https://elixir.bootlin.com/linux/v4.14.2/source/drivers/usb/host/xhci-
> > > > mem.c#L52
> > > > 
> > > > prints above are custom traces added right after dma_pool_zalloc()
> > > 
> > > For better understanding it would be good to have dma_pool_free() calls
> > > debugged as well.
> > 
> 
> Sudip has a full (394M unpacked) trace at:
> https://drive.google.com/open?id=1h-3r-1lfjg8oblBGkzdRIq8z3ZNgGZx-
> 

<snip>

> But then it gets stuck, for the whole ring2 dma_pool_zalloc() just returns the same dma address as the last segment for
> ring1:0x2d92b000. Last part of trace snippet is just another ring being freed.

A gentle ping on this. Any idea on what the problem might be and any
possible fix?

--
regards
Sudip
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Mathias Nyman June 21, 2018, 11:01 a.m. UTC | #3 
On 21.06.2018 03:53, Sudip Mukherjee wrote:
> Hi Mathias, Andy,
> 
> On Thu, Jun 07, 2018 at 10:40:03AM +0300, Mathias Nyman wrote:
>> On 06.06.2018 19:45, Sudip Mukherjee wrote:
>>> Hi Andy,
>>>
>>> And we meet again. :)
>>>
>>> On Wed, Jun 06, 2018 at 06:36:35PM +0300, Andy Shevchenko wrote:
>>>> On Wed, 2018-06-06 at 17:12 +0300, Mathias Nyman wrote:
>>>>> On 04.06.2018 18:28, Sudip Mukherjee wrote:
>>>>>> On Thu, May 24, 2018 at 04:35:34PM +0300, Mathias Nyman wrote:
>>>>>>>
>>>>
>>>>> Odd and unlikely, but to me this looks like some issue in allocating
>>>>> dma memory
>>>>> from pool using dma_pool_zalloc()
>>>>>
>>>>>
>>>>> Here's the story:
>>>>> Sudip sees usb issues on a Intel Atom based board with 4.14.2 kernel.
>>>>> All tracing points to dma_pool_zalloc() returning the same dma address
>>>>> block on
>>>>> consecutive calls.
>>>>>
>>>>> In the failing case dma_pool_zalloc() is called 3 - 6us apart.
>>>>>
>>>>> <...>-26362 [002] ....  1186.756739: xhci_ring_mem_detail: MATTU
>>>>> xhci_segment_alloc dma @ 0x000000002d92b000
>>>>> <...>-26362 [002] ....  1186.756745: xhci_ring_mem_detail: MATTU
>>>>> xhci_segment_alloc dma @ 0x000000002d92b000
>>>>> <...>-26362 [002] ....  1186.756748: xhci_ring_mem_detail: MATTU
>>>>> xhci_segment_alloc dma @ 0x000000002d92b000
>>>>>
>>>>> dma_pool_zalloc() is called from xhci_segment_alloc() in
>>>>> drivers/usb/host/xhci-mem.c
>>>>> see:
>>>>> https://elixir.bootlin.com/linux/v4.14.2/source/drivers/usb/host/xhci-
>>>>> mem.c#L52
>>>>>
>>>>> prints above are custom traces added right after dma_pool_zalloc()
>>>>
>>>> For better understanding it would be good to have dma_pool_free() calls
>>>> debugged as well.
>>>
>>
>> Sudip has a full (394M unpacked) trace at:
>> https://drive.google.com/open?id=1h-3r-1lfjg8oblBGkzdRIq8z3ZNgGZx-
>>
> 
> <snip>
> 
>> But then it gets stuck, for the whole ring2 dma_pool_zalloc() just returns the same dma address as the last segment for
>> ring1:0x2d92b000. Last part of trace snippet is just another ring being freed.
> 
> A gentle ping on this. Any idea on what the problem might be and any
> possible fix?
> 

I tried to reproduce it by quickly hacking xhci to allocate and free 50 segments each time
we normally allocate one segment from dmapool.
I let it run for 3 days on a Atom based platform, but could not reproduce it.

xhci testhack can be found here:

git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git dmapool-test
https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=dmapool-test

Tested by just leaving the following running for a few days:

while true; do echo 0 > authorized; sleep 3; echo 1 > authorized; sleep 3; done;
For some usb device (for example: /sys/bus/usb/devices/1-8)

Then grep logs for "MATTU dmatest match! "

Can you share a bit more details on the platform you are using, and what types of test you are running.
Does my test above trigger the case? (show "MATTU dmatest match!")

-Mathias

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Sudip Mukherjee June 25, 2018, 4:15 p.m. UTC | #4 
Hi Mathias,

On Thu, Jun 21, 2018 at 02:01:30PM +0300, Mathias Nyman wrote:
> On 21.06.2018 03:53, Sudip Mukherjee wrote:
> > Hi Mathias, Andy,
> > 
> > On Thu, Jun 07, 2018 at 10:40:03AM +0300, Mathias Nyman wrote:
> > > On 06.06.2018 19:45, Sudip Mukherjee wrote:
<snip>
> 
> git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git dmapool-test
> https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=dmapool-test
> 
> Tested by just leaving the following running for a few days:
> 
> while true; do echo 0 > authorized; sleep 3; echo 1 > authorized; sleep 3; done;
> For some usb device (for example: /sys/bus/usb/devices/1-8)
> 
> Then grep logs for "MATTU dmatest match! "
> 
> Can you share a bit more details on the platform you are using, and what types of test you are running.

Sorry for the delayed reply, I was in Tokyo for the OSS.

It is a board based on "Intel(R) Atom(TM) CPU  E3840  @ 1.91GHz".
The usb device in question is a bluetooth device:

Bus 001 Device 012: ID 8087:07dc Intel Corp.
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass          224 Wireless
  bDeviceSubClass         1 Radio Frequency
  bDeviceProtocol         1 Bluetooth
  bMaxPacketSize0        64
  idVendor           0x8087 Intel Corp.
  idProduct          0x07dc
  bcdDevice            0.01
  iManufacturer           0
  iProduct                0
  iSerial                 0
  bNumConfigurations      1

And the problem that we are seeing is with phone calls via bluetooth.

> Does my test above trigger the case? (show "MATTU dmatest match!")

I have kept it for tonight, will see the results tomorrow morning.
And I am using that same device in the usb script to change "authrized".

But looking at the code for dma_pool_alloc(), it seems 'dma' can have
same value again only if "*(int *)(page->vaddr + offset)" gets a value
of 0 in pool_initialise_page(). But I can't think of anyway how it
can be 0. I have also added some more debugs in the kernel to see what
might be going wrong there.

--
Regards
Sudip
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Sudip Mukherjee June 27, 2018, 11:59 a.m. UTC | #5 
Hi Mathias,

On Mon, Jun 25, 2018 at 05:15:00PM +0100, Sudip Mukherjee wrote:
> Hi Mathias,
> 
> On Thu, Jun 21, 2018 at 02:01:30PM +0300, Mathias Nyman wrote:
> > On 21.06.2018 03:53, Sudip Mukherjee wrote:
> > > Hi Mathias, Andy,
> > > 
> > > On Thu, Jun 07, 2018 at 10:40:03AM +0300, Mathias Nyman wrote:
> > > > On 06.06.2018 19:45, Sudip Mukherjee wrote:
<snip>
> > 
> > Can you share a bit more details on the platform you are using, and what types of test you are running.
> 
> Sorry for the delayed reply, I was in Tokyo for the OSS.
> 
> It is a board based on "Intel(R) Atom(TM) CPU  E3840  @ 1.91GHz".
> The usb device in question is a bluetooth device:
> 
> Bus 001 Device 012: ID 8087:07dc Intel Corp.
<snip>
> 
> And the problem that we are seeing is with phone calls via bluetooth.
> 
> > Does my test above trigger the case? (show "MATTU dmatest match!")
> 
> I have kept it for tonight, will see the results tomorrow morning.
> And I am using that same device in the usb script to change "authrized".

No, your test did not trigger the error. :(

But, my last night's test (with an added debug to get some extra trace for addresses) showed the same error of -
"Looking for event-dma", but looking at the ftrace, I could not see it getting same address from dma_pool_zalloc().

Can you please have a look at the dmesg and ftrace at:
https://drive.google.com/open?id=1nMy_qVxOQzcZNYa9bw7az9WiS2MZzdKo


--
Regards
Sudip
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Sudip Mukherjee June 27, 2018, 12:20 p.m. UTC | #6 
On Wed, Jun 27, 2018 at 12:59:48PM +0100, Sudip Mukherjee wrote:
> Hi Mathias,
> 
> On Mon, Jun 25, 2018 at 05:15:00PM +0100, Sudip Mukherjee wrote:
> > Hi Mathias,
> > 
> > On Thu, Jun 21, 2018 at 02:01:30PM +0300, Mathias Nyman wrote:
> > > On 21.06.2018 03:53, Sudip Mukherjee wrote:
> > > > Hi Mathias, Andy,
> > > > 
> > > > On Thu, Jun 07, 2018 at 10:40:03AM +0300, Mathias Nyman wrote:
> > > > > On 06.06.2018 19:45, Sudip Mukherjee wrote:
> <snip>
> > > 
> > > Can you share a bit more details on the platform you are using, and what types of test you are running.
> > 
> > Sorry for the delayed reply, I was in Tokyo for the OSS.
> > 
> > It is a board based on "Intel(R) Atom(TM) CPU  E3840  @ 1.91GHz".
> > The usb device in question is a bluetooth device:
> > 
> > Bus 001 Device 012: ID 8087:07dc Intel Corp.
> <snip>
> > 
> > And the problem that we are seeing is with phone calls via bluetooth.
> > 
> > > Does my test above trigger the case? (show "MATTU dmatest match!")
> > 
> > I have kept it for tonight, will see the results tomorrow morning.
> > And I am using that same device in the usb script to change "authrized".
> 
> No, your test did not trigger the error. :(
> 
> But, my last night's test (with an added debug to get some extra trace for addresses) showed the same error of -
> "Looking for event-dma", but looking at the ftrace, I could not see it getting same address from dma_pool_zalloc().
> 
> Can you please have a look at the dmesg and ftrace at:
> https://drive.google.com/open?id=1nMy_qVxOQzcZNYa9bw7az9WiS2MZzdKo

And to add to my previous mail, in another cycle where I do see the
same problem and my extra debugs give the following:

           <...>-23974 [002] ....   495.991276: xhci_ring_mem_detail: MATTU xhci_segment_alloc dma @ 0x000000002d21c000
           <...>-23974 [002] ....   495.991285: xhci_ring_mem_detail: SUDIP page details dma=0x000000002d21c000, vaddr=ed21c000, inuse=1, offset=0
           <...>-23974 [002] ....   495.991289: xhci_ring_mem_detail: MATTU xhci_segment_alloc dma @ 0x000000002d21c000
           <...>-23974 [002] ....   495.991292: xhci_ring_mem_detail: SUDIP page details dma=0x000000002d21c000, vaddr=ed21c000, inuse=2, offset=0
           <...>-23974 [002] ....   495.991295: xhci_ring_alloc: ISOC f0b62900: enq 0x000000002d21c000(0x000000002d21c000) deq 0x000000002d21c000(0x000000002d21c000) segs 2 stream 0 free_trbs 509 bounce 17 cycle 1
           <...>-23974 [002] ....   495.991298: xhci_ring_mem_detail: MATTU xhci_segment_alloc dma @ 0x000000002d21c000
           <...>-23974 [002] ....   495.991301: xhci_ring_mem_detail: SUDIP page details dma=0x000000002d21c000, vaddr=ed21c000, inuse=3, offset=0
           <...>-23974 [002] ....   495.991304: xhci_ring_mem_detail: MATTU xhci_segment_alloc dma @ 0x000000002d21c000
           <...>-23974 [002] ....   495.991306: xhci_ring_mem_detail: SUDIP page details dma=0x000000002d21c000, vaddr=ed21c000, inuse=4, offset=0


I am totally lost now. Are we looking at two different issues?
This log shows same addresses, my previous mail and log did not show
the same addresses. :(


--
Regards
Sudip
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Mathias Nyman June 29, 2018, 11:41 a.m. UTC | #7 
On 27.06.2018 14:59, Sudip Mukherjee wrote:
>>> Can you share a bit more details on the platform you are using, and what types of test you are running.
>>
>> It is a board based on "Intel(R) Atom(TM) CPU  E3840  @ 1.91GHz".
>> The usb device in question is a bluetooth device:
>>
>> Bus 001 Device 012: ID 8087:07dc Intel Corp.
> <snip>
>>
>> And the problem that we are seeing is with phone calls via bluetooth.
>>
>>> Does my test above trigger the case? (show "MATTU dmatest match!")
>>
>> I have kept it for tonight, will see the results tomorrow morning.
>> And I am using that same device in the usb script to change "authrized".
> 
> No, your test did not trigger the error. :(
> 
> But, my last night's test (with an added debug to get some extra trace for addresses) showed the same error of -
> "Looking for event-dma", but looking at the ftrace, I could not see it getting same address from dma_pool_zalloc().
> 
> Can you please have a look at the dmesg and ftrace at:
> https://drive.google.com/open?id=1nMy_qVxOQzcZNYa9bw7az9WiS2MZzdKo
> 

There is however freeing of the same dma address:

<...>-28448 [003] ....   492.025808: xhci_ring_free: ISOC f1ffb700: enq 0x000000002d31bcc0(0x000000002d31b000) deq 0x000000002d31b000(0x000000002d31b000) segs 2 stream 0 free_trbs 305 bounce 17 cycle 0
<...>-28448 [003] ....   492.025818: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ 0x000000002d31b000
<...>-28448 [003] ....   492.025823: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ 0x000000002d31b000
<...>-28448 [003] ....   492.025826: xhci_ring_free: ISOC f1f9b380: enq 0x000000002d31b140(0x000000002d31b000) deq 0x000000002d31b000(0x000000002d31b000) segs 2 stream 0 free_trbs 489 bounce 17 cycle 1
<...>-28448 [003] ....   492.025828: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ 0x000000002d31b000
<...>-28448 [003] ....   492.025830: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ 0x000000002d31b000

I'd guess it's still the same cause, maybe trace is not complete?

-Mathias
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Sudip Mukherjee June 30, 2018, 9:07 p.m. UTC | #8 
Hi Mathias,

On Fri, Jun 29, 2018 at 02:41:13PM +0300, Mathias Nyman wrote:
> On 27.06.2018 14:59, Sudip Mukherjee wrote:
> > > > Can you share a bit more details on the platform you are using, and what types of test you are running.
> > > 
> > > It is a board based on "Intel(R) Atom(TM) CPU  E3840  @ 1.91GHz".
> > > The usb device in question is a bluetooth device:
> > > 
<snip>
> > 
> 
> There is however freeing of the same dma address:
> 
> <...>-28448 [003] ....   492.025808: xhci_ring_free: ISOC f1ffb700: enq 0x000000002d31bcc0(0x000000002d31b000) deq 0x000000002d31b000(0x000000002d31b000) segs 2 stream 0 free_trbs 305 bounce 17 cycle 0
> <...>-28448 [003] ....   492.025818: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ 0x000000002d31b000
> <...>-28448 [003] ....   492.025823: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ 0x000000002d31b000
> <...>-28448 [003] ....   492.025826: xhci_ring_free: ISOC f1f9b380: enq 0x000000002d31b140(0x000000002d31b000) deq 0x000000002d31b000(0x000000002d31b000) segs 2 stream 0 free_trbs 489 bounce 17 cycle 1
> <...>-28448 [003] ....   492.025828: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ 0x000000002d31b000
> <...>-28448 [003] ....   492.025830: xhci_ring_mem_detail: MATTU xhci segment free seg->dma @ 0x000000002d31b000
> 
> I'd guess it's still the same cause, maybe trace is not complete?

It is either mutiple freeing of the same address or mutiple allocation
of the same address or a combination of both. To track the mutiple
allocation I added few extra debugging and it seems that the mutiple
allocation is only happening when someone accesses that memory and
makes the first 4 bytes (which holds the offset data) as 0. I have not
yet checked in what condition does it try to free the same address more
than once.
Then to track what is going on, I added the slub debugging and :(
I have attached part of dmesg for you to check.
Will appreciate your help in finding out the problem.


--
Regards
Sudip
[  383.096204] =============================================================================
[  383.096212] BUG kmalloc-96 (Tainted: G     U     O   ): Poison overwritten
[  383.096213] -----------------------------------------------------------------------------

[  383.096215] Disabling lock debugging due to kernel taint
[  383.096218] INFO: 0xdccd1b78-0xdccd1b7f. First byte 0x78 instead of 0x6b
[  383.096232] INFO: Allocated in xhci_ring_alloc.constprop.14+0x31/0x125 [xhci_hcd] age=227516 cpu=2 pid=21
[  383.096240] 	___slab_alloc.constprop.24+0x1fc/0x292
[  383.096243] 	__slab_alloc.isra.18.constprop.23+0x1c/0x25
[  383.096246] 	kmem_cache_alloc_trace+0x78/0x141
[  383.096252] 	xhci_ring_alloc.constprop.14+0x31/0x125 [xhci_hcd]
[  383.096259] 	xhci_endpoint_init+0x25f/0x30a [xhci_hcd]
[  383.096265] 	xhci_add_endpoint+0x126/0x149 [xhci_hcd]
[  383.096276] 	usb_hcd_alloc_bandwidth+0x26a/0x2a0 [usbcore]
[  383.096287] 	usb_set_interface+0xeb/0x25d [usbcore]
[  383.096292] 	btusb_work+0xeb/0x324 [btusb]
[  383.096296] 	process_one_work+0x163/0x2b2
[  383.096299] 	worker_thread+0x1a9/0x25c
[  383.096301] 	kthread+0xf8/0xfd
[  383.096306] 	ret_from_fork+0x2e/0x38
[  383.096314] INFO: Freed in xhci_ring_free+0xa7/0xc6 [xhci_hcd] age=197020 cpu=0 pid=324
[  383.096317] 	__slab_free+0x4b/0x27a
[  383.096319] 	kfree+0x12e/0x155
[  383.096325] 	xhci_ring_free+0xa7/0xc6 [xhci_hcd]
[  383.096331] 	xhci_free_endpoint_ring+0x16/0x20 [xhci_hcd]
[  383.096338] 	xhci_check_bandwidth+0x1bf/0x20e [xhci_hcd]
[  383.096348] 	usb_hcd_alloc_bandwidth+0x205/0x2a0 [usbcore]
[  383.096358] 	usb_set_interface+0xeb/0x25d [usbcore]
[  383.096361] 	btusb_work+0x228/0x324 [btusb]
[  383.096364] 	process_one_work+0x163/0x2b2
[  383.096367] 	worker_thread+0x1a9/0x25c
[  383.096370] 	kthread+0xf8/0xfd
[  383.096373] 	ret_from_fork+0x2e/0x38
[  383.096376] INFO: Slab 0xf457e080 objects=29 used=29 fp=0x  (null) flags=0x40008100
[  383.096379] INFO: Object 0xdccd1b60 @offset=7008 fp=0xdccd0350

[  383.096383] Redzone dccd1b58: bb bb bb bb bb bb bb bb                          ........
[  383.096386] Object dccd1b60: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[  383.096388] Object dccd1b70: 6b 6b 6b 6b 6b 6b 6b 6b 78 1b cd dc 78 1b cd dc  kkkkkkkkx...x...
[  383.096390] Object dccd1b80: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[  383.096393] Object dccd1b90: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[  383.096395] Object dccd1ba0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[  383.096397] Object dccd1bb0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b a5  kkkkkkkkkkkkkkk.
[  383.096400] Redzone dccd1bc0: bb bb bb bb                                      ....
[  383.096402] Padding dccd1c68: 5a 5a 5a 5a 5a 5a 5a 5a                          ZZZZZZZZ
[  383.096407] CPU: 2 PID: 133 Comm: weston Tainted: G    BU     O    4.14.47-20180606-dca26511b26cdcd4446c1eba652b573a6fbca607 #1
[  383.096409] Hardware name: xxx yyy/zzz, BIOS 2017.01-00087-g43e04de 08/30/2017
[  383.096411] Call Trace:
[  383.096417]  dump_stack+0x47/0x5b
[  383.096421]  print_trailer+0x12b/0x133
[  383.096425]  check_bytes_and_report+0x6c/0xae
[  383.096428]  check_object+0x10a/0x1db
[  383.096433]  alloc_debug_processing+0x79/0x123
[  383.096436]  ___slab_alloc.constprop.24+0x1fc/0x292
[  383.096442]  ? drm_atomic_helper_setup_commit+0x60/0x2f4
[  383.096446]  ? drm_atomic_helper_setup_commit+0x60/0x2f4
[  383.096450]  ? vlv_compute_intermediate_wm+0x157/0x16c
[  383.096454]  ? skl_ddb_min_alloc+0xf3/0xf3
[  383.096459]  ? intel_crtc_atomic_check+0xd4/0x198
[  383.096463]  __slab_alloc.isra.18.constprop.23+0x1c/0x25
[  383.096466]  ? __slab_alloc.isra.18.constprop.23+0x1c/0x25
[  383.096470]  kmem_cache_alloc_trace+0x78/0x141
[  383.096474]  ? drm_atomic_helper_setup_commit+0x60/0x2f4
[  383.096478]  drm_atomic_helper_setup_commit+0x60/0x2f4
[  383.096482]  ? intel_atomic_commit_tail+0xa84/0xa84
[  383.096486]  intel_atomic_commit+0x21/0x1b2
[  383.096490]  ? intel_atomic_commit_tail+0xa84/0xa84
[  383.096495]  drm_atomic_nonblocking_commit+0x42/0x4c
[  383.096499]  drm_mode_atomic_ioctl+0x680/0x75e
[  383.096505]  ? drm_atomic_set_property+0x442/0x442
[  383.096509]  drm_ioctl_kernel+0x52/0x88
[  383.096513]  drm_ioctl+0x1fc/0x2c1
[  383.096516]  ? drm_atomic_set_property+0x442/0x442
[  383.096522]  ? probe_sched_wakeup+0x2e/0x30
[  383.096526]  ? ttwu_do_wakeup.isra.19+0x157/0x167
[  383.096530]  ? ttwu_do_activate+0x65/0x6e
[  383.096534]  ? drm_getstats+0x17/0x17
[  383.096538]  vfs_ioctl+0x1f/0x29
[  383.096541]  do_vfs_ioctl+0x4f3/0x562
[  383.096545]  ? smk_curacc+0x24/0x29
[  383.096550]  ? smack_file_ioctl+0x4d/0x52
[  383.096553]  ? smack_file_lock+0x29/0x29
[  383.096556]  ? security_file_ioctl+0x34/0x45
[  383.096559]  SyS_ioctl+0x42/0x5b
[  383.096564]  do_fast_syscall_32+0xd3/0x171
[  383.096568]  entry_SYSENTER_32+0x47/0x71
[  383.096571] EIP: 0xb7f1aab1
[  383.096573] EFLAGS: 00200282 CPU: 2
[  383.096575] EAX: ffffffda EBX: 0000000f ECX: c03864bb EDX: bfa84338
[  383.096578] ESI: bfa84338 EDI: c03864bb EBP: bfa842d8 ESP: bfa84298
[  383.096580]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[  383.096585] FIX kmalloc-96: Restoring 0xdccd1b78-0xdccd1b7f=0x6b

[  383.096587] FIX kmalloc-96: Marking all objects used
[  405.587632] xhci_hcd 0000:00:14.0: dma_pool_alloc xHCI ring segments, eca42000 (corrupted)
[  405.587639] 00000000: 00 10 00 00 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587642] 00000010: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587644] 00000020: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587647] 00000030: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587649] 00000040: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587651] 00000050: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587654] 00000060: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587656] 00000070: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587658] 00000080: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587661] 00000090: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587663] 000000a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587665] 000000b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587668] 000000c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587670] 000000d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587672] 000000e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587675] 000000f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587677] 00000100: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587679] 00000110: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587682] 00000120: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587684] 00000130: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587686] 00000140: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587689] 00000150: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587691] 00000160: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587694] 00000170: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587696] 00000180: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587698] 00000190: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587701] 000001a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587703] 000001b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587705] 000001c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587708] 000001d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587710] 000001e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587712] 000001f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587715] 00000200: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587717] 00000210: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587720] 00000220: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587722] 00000230: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587724] 00000240: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587727] 00000250: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587729] 00000260: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587731] 00000270: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587734] 00000280: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587736] 00000290: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587738] 000002a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587741] 000002b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587743] 000002c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587746] 000002d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587748] 000002e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587750] 000002f0: 00 00 00 00 00 00 00 00 00 00 00 00 01 20 00 00  ............. ..
[  405.587753] 00000300: 00 00 00 00 00 00 00 00 00 00 00 00 01 20 00 00  ............. ..
[  405.587755] 00000310: 00 00 00 00 00 00 00 00 00 00 00 00 01 20 00 00  ............. ..
[  405.587757] 00000320: 00 00 00 00 00 00 00 00 00 00 00 00 01 20 00 00  ............. ..
[  405.587760] 00000330: 00 00 00 00 00 00 00 00 00 00 00 00 01 20 00 00  ............. ..
[  405.587762] 00000340: 00 00 00 00 00 00 00 00 00 00 00 00 01 20 00 00  ............. ..
[  405.587764] 00000350: 00 00 00 00 00 00 00 00 00 00 00 00 01 20 00 00  ............. ..
[  405.587766] 00000360: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587769] 00000370: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587771] 00000380: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587773] 00000390: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587776] 000003a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587778] 000003b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587780] 000003c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587783] 000003d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587785] 000003e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587787] 000003f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587790] 00000400: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587792] 00000410: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587794] 00000420: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587797] 00000430: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587799] 00000440: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587801] 00000450: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587804] 00000460: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587806] 00000470: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587808] 00000480: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587811] 00000490: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587813] 000004a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587816] 000004b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587818] 000004c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587820] 000004d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587823] 000004e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587825] 000004f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587827] 00000500: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587830] 00000510: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587832] 00000520: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587834] 00000530: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587837] 00000540: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587839] 00000550: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587841] 00000560: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587844] 00000570: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587846] 00000580: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587848] 00000590: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587851] 000005a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587853] 000005b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587855] 000005c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587858] 000005d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587860] 000005e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587862] 000005f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587865] 00000600: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587867] 00000610: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587869] 00000620: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587872] 00000630: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587874] 00000640: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587876] 00000650: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587879] 00000660: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587881] 00000670: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587883] 00000680: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587886] 00000690: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587888] 000006a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587890] 000006b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587893] 000006c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587895] 000006d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587897] 000006e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587900] 000006f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587902] 00000700: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587904] 00000710: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587907] 00000720: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587909] 00000730: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587912] 00000740: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587914] 00000750: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587916] 00000760: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587919] 00000770: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587921] 00000780: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587923] 00000790: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587926] 000007a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587928] 000007b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587930] 000007c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587933] 000007d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587935] 000007e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587937] 000007f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587940] 00000800: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587942] 00000810: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587944] 00000820: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587947] 00000830: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587949] 00000840: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587952] 00000850: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587954] 00000860: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587956] 00000870: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587959] 00000880: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587961] 00000890: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587963] 000008a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587966] 000008b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587968] 000008c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587970] 000008d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587973] 000008e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587975] 000008f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587977] 00000900: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587980] 00000910: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587982] 00000920: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587985] 00000930: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587987] 00000940: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587989] 00000950: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587992] 00000960: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587994] 00000970: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587996] 00000980: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.587999] 00000990: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588001] 000009a0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588003] 000009b0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588006] 000009c0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588009] 000009d0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588011] 000009e0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588013] 000009f0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588016] 00000a00: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588018] 00000a10: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588020] 00000a20: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588023] 00000a30: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588025] 00000a40: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588028] 00000a50: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588030] 00000a60: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588033] 00000a70: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588035] 00000a80: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588037] 00000a90: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588040] 00000aa0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588042] 00000ab0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588044] 00000ac0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588047] 00000ad0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588049] 00000ae0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588052] 00000af0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588054] 00000b00: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588056] 00000b10: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588059] 00000b20: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588061] 00000b30: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588063] 00000b40: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588066] 00000b50: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588068] 00000b60: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588070] 00000b70: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588073] 00000b80: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588075] 00000b90: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588078] 00000ba0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588080] 00000bb0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588082] 00000bc0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588085] 00000bd0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588087] 00000be0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588089] 00000bf0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588092] 00000c00: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588094] 00000c10: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588096] 00000c20: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588099] 00000c30: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588101] 00000c40: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588103] 00000c50: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588106] 00000c60: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588108] 00000c70: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588111] 00000c80: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588113] 00000c90: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588115] 00000ca0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588118] 00000cb0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588120] 00000cc0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588122] 00000cd0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588125] 00000ce0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588127] 00000cf0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588130] 00000d00: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588132] 00000d10: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588134] 00000d20: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588137] 00000d30: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588139] 00000d40: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588141] 00000d50: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588144] 00000d60: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588146] 00000d70: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588148] 00000d80: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588151] 00000d90: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588153] 00000da0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588155] 00000db0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588158] 00000dc0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588160] 00000dd0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588163] 00000de0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588165] 00000df0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588167] 00000e00: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588170] 00000e10: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588172] 00000e20: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588174] 00000e30: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588177] 00000e40: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588179] 00000e50: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588181] 00000e60: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588184] 00000e70: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588186] 00000e80: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588189] 00000e90: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588191] 00000ea0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588193] 00000eb0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588196] 00000ec0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588198] 00000ed0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588200] 00000ee0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588203] 00000ef0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588205] 00000f00: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588207] 00000f10: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588210] 00000f20: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588212] 00000f30: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588215] 00000f40: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588217] 00000f50: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588219] 00000f60: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588222] 00000f70: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588224] 00000f80: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588226] 00000f90: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588229] 00000fa0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588231] 00000fb0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588233] 00000fc0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588236] 00000fd0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588238] 00000fe0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.588241] 00000ff0: a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7 a7  ................
[  405.589593] BLUETOOTH: isoc_rx_ep_wMaxPacketSize 17
[  405.589618] BLUETOOTH: isoc_rx_ep_wMaxPacketSize 17
[  405.599447] btusb_isoc_complete: 380 callbacks suppressed
[  405.599450] BLUETOOTH:  SCO usb pack length 0
[  405.599453] BLUETOOTH:  SCO usb pack length 0
[  405.599455] BLUETOOTH:  SCO usb pack length 0
[  405.599457] BLUETOOTH:  SCO usb pack length 0
[  405.599458] BLUETOOTH:  SCO usb pack length 0
[  405.599460] BLUETOOTH:  SCO usb pack length 0
[  405.599461] BLUETOOTH:  SCO usb pack length 0
[  405.599463] BLUETOOTH:  SCO usb pack length 0
[  405.599464] BLUETOOTH:  SCO usb pack length 0
[  405.599466] BLUETOOTH:  SCO usb pack length 0
[  405.639502] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  405.639520] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  405.649536] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  405.649556] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  405.649566] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  405.649575] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  405.659529] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  410.611473] btusb_isoc_complete: 5000 callbacks suppressed
[  410.611476] BLUETOOTH:  SCO usb pack length 17
[  410.611491] BLUETOOTH:  SCO usb pack length 17
[  410.611493] BLUETOOTH:  SCO usb pack length 17
[  410.611504] BLUETOOTH:  SCO usb pack length 17
[  410.611516] BLUETOOTH:  SCO usb pack length 17
[  410.611518] BLUETOOTH:  SCO usb pack length 17
[  410.611521] BLUETOOTH:  SCO usb pack length 17
[  410.611532] BLUETOOTH:  SCO usb pack length 17
[  410.611534] BLUETOOTH:  SCO usb pack length 17
[  410.611537] BLUETOOTH:  SCO usb pack length 17
[  415.623476] btusb_isoc_complete: 5000 callbacks suppressed
[  415.623479] BLUETOOTH:  SCO usb pack length 17
[  415.623495] BLUETOOTH:  SCO usb pack length 17
[  415.623497] BLUETOOTH:  SCO usb pack length 17
[  415.623508] BLUETOOTH:  SCO usb pack length 17
[  415.623522] BLUETOOTH:  SCO usb pack length 17
[  415.623524] BLUETOOTH:  SCO usb pack length 17
[  415.623527] BLUETOOTH:  SCO usb pack length 17
[  415.623537] BLUETOOTH:  SCO usb pack length 17
[  415.623539] BLUETOOTH:  SCO usb pack length 17
[  415.623542] BLUETOOTH:  SCO usb pack length 17
[  420.635481] btusb_isoc_complete: 5000 callbacks suppressed
[  420.635483] BLUETOOTH:  SCO usb pack length 17
[  420.635499] BLUETOOTH:  SCO usb pack length 17
[  420.635501] BLUETOOTH:  SCO usb pack length 17
[  420.635513] BLUETOOTH:  SCO usb pack length 17
[  420.635527] BLUETOOTH:  SCO usb pack length 17
[  420.635529] BLUETOOTH:  SCO usb pack length 17
[  420.635531] BLUETOOTH:  SCO usb pack length 17
[  420.635542] BLUETOOTH:  SCO usb pack length 17
[  420.635544] BLUETOOTH:  SCO usb pack length 17
[  420.635547] BLUETOOTH:  SCO usb pack length 17
[  425.647489] btusb_isoc_complete: 5000 callbacks suppressed
[  425.647492] BLUETOOTH:  SCO usb pack length 17
[  425.647508] BLUETOOTH:  SCO usb pack length 17
[  425.647510] BLUETOOTH:  SCO usb pack length 17
[  425.647523] BLUETOOTH:  SCO usb pack length 17
[  425.647536] BLUETOOTH:  SCO usb pack length 17
[  425.647537] BLUETOOTH:  SCO usb pack length 17
[  425.647540] BLUETOOTH:  SCO usb pack length 17
[  425.647551] BLUETOOTH:  SCO usb pack length 17
[  425.647553] BLUETOOTH:  SCO usb pack length 17
[  425.647556] BLUETOOTH:  SCO usb pack length 17
[  430.659487] btusb_isoc_complete: 5000 callbacks suppressed
[  430.659489] BLUETOOTH:  SCO usb pack length 17
[  430.659505] BLUETOOTH:  SCO usb pack length 17
[  430.659507] BLUETOOTH:  SCO usb pack length 17
[  430.659518] BLUETOOTH:  SCO usb pack length 17
[  430.659530] BLUETOOTH:  SCO usb pack length 17
[  430.659532] BLUETOOTH:  SCO usb pack length 17
[  430.659535] BLUETOOTH:  SCO usb pack length 17
[  430.659546] BLUETOOTH:  SCO usb pack length 17
[  430.659548] BLUETOOTH:  SCO usb pack length 17
[  430.659551] BLUETOOTH:  SCO usb pack length 17
[  435.671494] btusb_isoc_complete: 5000 callbacks suppressed
[  435.671496] BLUETOOTH:  SCO usb pack length 17
[  435.671511] BLUETOOTH:  SCO usb pack length 17
[  435.671513] BLUETOOTH:  SCO usb pack length 17
[  435.671526] BLUETOOTH:  SCO usb pack length 17
[  435.671539] BLUETOOTH:  SCO usb pack length 17
[  435.671541] BLUETOOTH:  SCO usb pack length 17
[  435.671543] BLUETOOTH:  SCO usb pack length 17
[  435.671555] BLUETOOTH:  SCO usb pack length 17
[  435.671556] BLUETOOTH:  SCO usb pack length 17
[  435.671559] BLUETOOTH:  SCO usb pack length 17
[  436.089810] Bluetooth: hci0 SCO packet for unknown connection handle 266
[  436.089822] Bluetooth: hci0 SCO packet for unknown connection handle 266
[  436.089838] Bluetooth: hci0 SCO packet for unknown connection handle 266
[  467.960870] BLUETOOTH: isoc_rx_ep_wMaxPacketSize 17
[  467.960893] BLUETOOTH: isoc_rx_ep_wMaxPacketSize 17
[  467.970389] btusb_isoc_complete: 410 callbacks suppressed
[  467.970392] BLUETOOTH:  SCO usb pack length 0
[  467.970395] BLUETOOTH:  SCO usb pack length 0
[  467.970397] BLUETOOTH:  SCO usb pack length 0
[  467.970398] BLUETOOTH:  SCO usb pack length 0
[  467.970400] BLUETOOTH:  SCO usb pack length 0
[  467.970401] BLUETOOTH:  SCO usb pack length 0
[  467.970403] BLUETOOTH:  SCO usb pack length 0
[  467.970404] BLUETOOTH:  SCO usb pack length 0
[  467.970406] BLUETOOTH:  SCO usb pack length 0
[  467.970407] BLUETOOTH:  SCO usb pack length 0
[  468.010493] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  468.010507] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  468.010529] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  468.020504] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  468.020522] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  468.020532] Bluetooth: hci0 SCO packet for unknown connection handle 0
[  472.982396] btusb_isoc_complete: 5000 callbacks suppressed
[  472.982399] BLUETOOTH:  SCO usb pack length 17
[  472.982412] BLUETOOTH:  SCO usb pack length 17
[  472.982427] BLUETOOTH:  SCO usb pack length 17
[  472.982430] BLUETOOTH:  SCO usb pack length 17
[  472.982435] BLUETOOTH:  SCO usb pack length 17
[  472.982447] BLUETOOTH:  SCO usb pack length 17
[  472.982449] BLUETOOTH:  SCO usb pack length 17
[  472.982455] BLUETOOTH:  SCO usb pack length 17
[  472.982471] BLUETOOTH:  SCO usb pack length 17
[  472.982473] BLUETOOTH:  SCO usb pack length 17
[  477.994400] btusb_isoc_complete: 5000 callbacks suppressed
[  477.994402] BLUETOOTH:  SCO usb pack length 17
[  477.994411] BLUETOOTH:  SCO usb pack length 17
[  477.994425] BLUETOOTH:  SCO usb pack length 17
[  477.994427] BLUETOOTH:  SCO usb pack length 17
[  477.994433] BLUETOOTH:  SCO usb pack length 17
[  477.994446] BLUETOOTH:  SCO usb pack length 17
[  477.994448] BLUETOOTH:  SCO usb pack length 17
[  477.994453] BLUETOOTH:  SCO usb pack length 17
[  477.994466] BLUETOOTH:  SCO usb pack length 17
[  477.994468] BLUETOOTH:  SCO usb pack length 17
[  480.687305] =============================================================================
[  480.687313] BUG kmalloc-96 (Tainted: G    BU     O   ): Poison overwritten
[  480.687314] -----------------------------------------------------------------------------

[  480.687318] INFO: 0xdd3409f8-0xdd3409ff. First byte 0xf8 instead of 0x6b
[  480.687332] INFO: Allocated in xhci_ring_alloc.constprop.14+0x31/0x125 [xhci_hcd] age=262619 cpu=0 pid=324
[  480.687340] 	___slab_alloc.constprop.24+0x1fc/0x292
[  480.687343] 	__slab_alloc.isra.18.constprop.23+0x1c/0x25
[  480.687346] 	kmem_cache_alloc_trace+0x78/0x141
[  480.687352] 	xhci_ring_alloc.constprop.14+0x31/0x125 [xhci_hcd]
[  480.687359] 	xhci_endpoint_init+0x25f/0x30a [xhci_hcd]
[  480.687365] 	xhci_add_endpoint+0x126/0x149 [xhci_hcd]
[  480.687377] 	usb_hcd_alloc_bandwidth+0x26a/0x2a0 [usbcore]
[  480.687387] 	usb_set_interface+0xeb/0x25d [usbcore]
[  480.687393] 	btusb_work+0xeb/0x324 [btusb]
[  480.687398] 	process_one_work+0x163/0x2b2
[  480.687401] 	worker_thread+0x1a9/0x25c
[  480.687404] 	kthread+0xf8/0xfd
[  480.687409] 	ret_from_fork+0x2e/0x38
[  480.687417] INFO: Freed in xhci_ring_free+0xa7/0xc6 [xhci_hcd] age=232052 cpu=0 pid=324
[  480.687419] 	__slab_free+0x4b/0x27a
[  480.687422] 	kfree+0x12e/0x155
[  480.687428] 	xhci_ring_free+0xa7/0xc6 [xhci_hcd]
[  480.687434] 	xhci_free_endpoint_ring+0x16/0x20 [xhci_hcd]
[  480.687440] 	xhci_check_bandwidth+0x1bf/0x20e [xhci_hcd]
[  480.687451] 	usb_hcd_alloc_bandwidth+0x205/0x2a0 [usbcore]
[  480.687461] 	usb_set_interface+0xeb/0x25d [usbcore]
[  480.687464] 	btusb_work+0x228/0x324 [btusb]
[  480.687467] 	process_one_work+0x163/0x2b2
[  480.687470] 	worker_thread+0x1a9/0x25c
[  480.687473] 	kthread+0xf8/0xfd
[  480.687476] 	ret_from_fork+0x2e/0x38
[  480.687480] INFO: Slab 0xf458e200 objects=29 used=29 fp=0x  (null) flags=0x40008100
[  480.687482] INFO: Object 0xdd3409e0 @offset=2528 fp=0xdd340e40

[  480.687486] Redzone dd3409d8: bb bb bb bb bb bb bb bb                          ........
[  480.687489] Object dd3409e0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[  480.687491] Object dd3409f0: 6b 6b 6b 6b 6b 6b 6b 6b f8 09 34 dd f8 09 34 dd  kkkkkkkk..4...4.
[  480.687494] Object dd340a00: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[  480.687496] Object dd340a10: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[  480.687498] Object dd340a20: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[  480.687501] Object dd340a30: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b a5  kkkkkkkkkkkkkkk.
[  480.687503] Redzone dd340a40: bb bb bb bb                                      ....
[  480.687505] Padding dd340ae8: 5a 5a 5a 5a 5a 5a 5a 5a                          ZZZZZZZZ
[  480.687510] CPU: 2 PID: 133 Comm: weston Tainted: G    BU     O    4.14.47-20180606-dca26511b26cdcd4446c1eba652b573a6fbca607 #1
[  480.687512] Hardware name: xxx yyy/zzz, BIOS 2017.01-00087-g43e04de 08/30/2017
[  480.687514] Call Trace:
[  480.687521]  dump_stack+0x47/0x5b
[  480.687525]  print_trailer+0x12b/0x133
[  480.687528]  check_bytes_and_report+0x6c/0xae
[  480.687532]  check_object+0x10a/0x1db
[  480.687536]  alloc_debug_processing+0x79/0x123
[  480.687540]  ___slab_alloc.constprop.24+0x1fc/0x292
[  480.687546]  ? drm_atomic_helper_setup_commit+0x60/0x2f4
[  480.687549]  ? drm_atomic_helper_setup_commit+0x60/0x2f4
[  480.687554]  ? vlv_compute_intermediate_wm+0x157/0x16c
[  480.687558]  ? skl_ddb_min_alloc+0xf3/0xf3
[  480.687563]  ? intel_crtc_atomic_check+0xd4/0x198
[  480.687567]  __slab_alloc.isra.18.constprop.23+0x1c/0x25
[  480.687570]  ? __slab_alloc.isra.18.constprop.23+0x1c/0x25
[  480.687574]  kmem_cache_alloc_trace+0x78/0x141
[  480.687578]  ? drm_atomic_helper_setup_commit+0x60/0x2f4
[  480.687582]  drm_atomic_helper_setup_commit+0x60/0x2f4
[  480.687586]  ? intel_atomic_commit_tail+0xa84/0xa84
[  480.687590]  intel_atomic_commit+0x21/0x1b2
[  480.687594]  ? intel_atomic_commit_tail+0xa84/0xa84
[  480.687599]  drm_atomic_nonblocking_commit+0x42/0x4c
[  480.687604]  drm_mode_atomic_ioctl+0x680/0x75e
[  480.687610]  ? drm_atomic_set_property+0x442/0x442
[  480.687614]  drm_ioctl_kernel+0x52/0x88
[  480.687618]  drm_ioctl+0x1fc/0x2c1
[  480.687622]  ? drm_atomic_set_property+0x442/0x442
[  480.687627]  ? probe_sched_wakeup+0x2e/0x30
[  480.687632]  ? ttwu_do_wakeup.isra.19+0x157/0x167
[  480.687636]  ? ttwu_do_activate+0x65/0x6e
[  480.687639]  ? __fget+0x5f/0x67
[  480.687642]  ? drm_getstats+0x17/0x17
[  480.687646]  vfs_ioctl+0x1f/0x29
[  480.687650]  do_vfs_ioctl+0x4f3/0x562
[  480.687654]  ? smk_curacc+0x24/0x29
[  480.687659]  ? smack_file_ioctl+0x4d/0x52
[  480.687663]  ? smack_file_lock+0x29/0x29
[  480.687666]  ? security_file_ioctl+0x34/0x45
[  480.687669]  SyS_ioctl+0x42/0x5b
[  480.687674]  do_fast_syscall_32+0xd3/0x171
[  480.687678]  entry_SYSENTER_32+0x47/0x71
[  480.687681] EIP: 0xb7f1aab1
[  480.687683] EFLAGS: 00200282 CPU: 2
[  480.687686] EAX: ffffffda EBX: 0000000f ECX: c03864bb EDX: bfa84438
[  480.687688] ESI: bfa84438 EDI: c03864bb EBP: bfa843d8 ESP: bfa84398
[  480.687691]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[  480.687696] FIX kmalloc-96: Restoring 0xdd3409f8-0xdd3409ff=0x6b

[  480.687698] FIX kmalloc-96: Marking all objects used
diff mbox

Patch

diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c
index e5ace89..7d343ad 100644
--- a/drivers/usb/host/xhci-mem.c
+++ b/drivers/usb/host/xhci-mem.c
@@ -44,10 +44,15 @@  static struct xhci_segment *xhci_segment_alloc(struct xhci_hcd *xhci,
  		return NULL;
  	}
  
+	xhci_dbg_trace(xhci,  trace_xhci_ring_mem_detail,
+		       "MATTU xhci_segment_alloc dma @ %pad", &dma);
+
  	if (max_packet) {
  		seg->bounce_buf = kzalloc(max_packet, flags);
  		if (!seg->bounce_buf) {
  			dma_pool_free(xhci->segment_pool, seg->trbs, dma);
+			xhci_dbg_trace(xhci,  trace_xhci_ring_mem_detail,
+				       "MATTU xhci segment free dma @ %pad", &dma);
  			kfree(seg);
  			return NULL;
  		}
@@ -58,6 +63,9 @@  static struct xhci_segment *xhci_segment_alloc(struct xhci_hcd *xhci,
  			seg->trbs[i].link.control |= cpu_to_le32(TRB_CYCLE);
  	}
  	seg->dma = dma;
+	xhci_dbg_trace(xhci,  trace_xhci_ring_mem_detail,
+		       "MATTU xhci segment alloc seg->dma @ %pad", &seg->dma);
+
  	seg->next = NULL;
  
  	return seg;
@@ -67,6 +75,8 @@  static void xhci_segment_free(struct xhci_hcd *xhci, struct xhci_segment *seg)
  {
  	if (seg->trbs) {
  		dma_pool_free(xhci->segment_pool, seg->trbs, seg->dma);
+		xhci_dbg_trace(xhci,  trace_xhci_ring_mem_detail,
+			       "MATTU xhci segment free seg->dma @ %p", &seg->dma);
  		seg->trbs = NULL;
  	}
  	kfree(seg->bounce_buf);
diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h
index 35bdd06..951e371 100644
--- a/drivers/usb/host/xhci-trace.h
+++ b/drivers/usb/host/xhci-trace.h
@@ -72,6 +72,11 @@  DEFINE_EVENT(xhci_log_msg, xhci_dbg_ring_expansion,
  	TP_ARGS(vaf)
  );
  
+DEFINE_EVENT(xhci_log_msg, xhci_ring_mem_detail,
+	TP_PROTO(struct va_format *vaf),
+	TP_ARGS(vaf)
+);
+
  DECLARE_EVENT_CLASS(xhci_log_ctx,
  	TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx,
  		 unsigned int ep_num),