NetBSD Problem Report #54322

From martin@aprisoft.de  Mon Jun 24 09:14:30 2019
Return-Path: <martin@aprisoft.de>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
	(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
	(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 9F1347A174
	for <gnats-bugs@gnats.NetBSD.org>; Mon, 24 Jun 2019 09:14:30 +0000 (UTC)
Message-Id: <20190624091420.9AEBC5CC84B@emmas.aprisoft.de>
Date: Mon, 24 Jun 2019 11:14:20 +0200 (CEST)
From: martin@NetBSD.org
Reply-To: martin@NetBSD.org
To: gnats-bugs@NetBSD.org
Subject: strange kdump output
X-Send-Pr-Version: 3.95

>Number:         54322
>Category:       kern
>Synopsis:       strange kdump output
>Confidential:   no
>Severity:       non-critical
>Priority:       medium
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Mon Jun 24 09:15:00 +0000 2019
>Last-Modified:  Thu Jul 04 20:00:01 +0000 2019
>Originator:     Martin Husemann
>Release:        NetBSD 8.99.47
>Organization:
The NetBSD Foundation, Inc.
>Environment:
System: NetBSD martins.aprisoft.de 8.99.47 NetBSD 8.99.47 (GENERIC) #0: Fri Jun 21 16:57:12 UTC 2019 mkrepro@mkrepro.NetBSD.org:/usr/src/sys/arch/amd64/compile/GENERIC amd64
Architecture: x86_64
Machine: amd64
>Description:

While ktracing a threaded application I noticed strange output in kdump:

  6851      1 gxemul   CALL  read(4,0x7d05e3f9e000,0x1000)
  6851      1 gxemul   GIO   fd 4 read 4088 bytes
[... data content stripped ...]
  6851      1 gxemul   GIO   fd 4 read 8 bytes
       "%\M^@\M^@\0\^D\0@\^P"
  6851      1 gxemul   RET   read 4096/0x1000

I expected a request of 0x1000 to just trigger the transfer of upto
4096/0x1000 bytes. Why is GIO accounting for additional stuff?

>How-To-Repeat:
Not sure, seems to be reproducable for me.

>Fix:
n/a

>Audit-Trail:
From: matthew green <mrg@eterna.com.au>
To: gnats-bugs@netbsd.org, martin@netbsd.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org,
    netbsd-bugs@netbsd.org
Subject: re: kern/54322: strange kdump output
Date: Mon, 24 Jun 2019 19:47:55 +1000

 > While ktracing a threaded application I noticed strange output in kdump:
 > 
 >   6851      1 gxemul   CALL  read(4,0x7d05e3f9e000,0x1000)
 >   6851      1 gxemul   GIO   fd 4 read 4088 bytes
 > [... data content stripped ...]
 >   6851      1 gxemul   GIO   fd 4 read 8 bytes
 >        "%\M^@\M^@\0\^D\0@\^P"
 >   6851      1 gxemul   RET   read 4096/0x1000
 > 
 > I expected a request of 0x1000 to just trigger the transfer of upto
 > 4096/0x1000 bytes. Why is GIO accounting for additional stuff?

 what is fd4?  is it perhaps a block device or a file system
 with 4KB blocks?


 .mrg.

From: Martin Husemann <martin@duskware.de>
To: matthew green <mrg@eterna.com.au>
Cc: gnats-bugs@netbsd.org
Subject: Re: kern/54322: strange kdump output
Date: Mon, 24 Jun 2019 12:09:00 +0200

 On Mon, Jun 24, 2019 at 07:47:55PM +1000, matthew green wrote:
 > > I expected a request of 0x1000 to just trigger the transfer of upto
 > > 4096/0x1000 bytes. Why is GIO accounting for additional stuff?
 > 
 > what is fd4?  is it perhaps a block device or a file system
 > with 4KB blocks?

 A plain file (disk image) on an FFSv2 file system (fsize 2048/bsize 16384),
 don't think the hard disk has 4k sectors (at least no trace of that in dmesg).

 Martin

From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: kern/54322: strange kdump output
Date: Thu, 4 Jul 2019 19:55:00 +0000

 On Mon, Jun 24, 2019 at 09:15:01AM +0000, martin@NetBSD.org wrote:
  > While ktracing a threaded application I noticed strange output in kdump:
  > 
  >   6851      1 gxemul   CALL  read(4,0x7d05e3f9e000,0x1000)
  >   6851      1 gxemul   GIO   fd 4 read 4088 bytes
  > [... data content stripped ...]
  >   6851      1 gxemul   GIO   fd 4 read 8 bytes
  >        "%\M^@\M^@\0\^D\0@\^P"
  >   6851      1 gxemul   RET   read 4096/0x1000
  > 
  > I expected a request of 0x1000 to just trigger the transfer of upto
  > 4096/0x1000 bytes. Why is GIO accounting for additional stuff?

 Well, it did read 4096 bytes. Though it's odd that it should do it in
 two chunks. However, it looks to me like this is a ktrace artifact --
 the ktrace code is not super clear but it looks like ktealloc() does
 one page at a time and ktr_io loops until it finishes. Meanwhile
 there's a ktrace header to stick into the buffer, and I'm guessing
 that header's 8 bytes, so the first ktrace record gets all but 8 bytes
 of the block and the rest goes in a second record.

 -- 
 David A. Holland
 dholland@netbsd.org

Home	PR Database Search