NetBSD Problem Report #54796

From tsutsui@ceres.dti.ne.jp  Tue Dec 24 12:15:01 2019
Return-Path: <tsutsui@ceres.dti.ne.jp>
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 DE1C17A17C
	for <gnats-bugs@gnats.NetBSD.org>; Tue, 24 Dec 2019 12:15:01 +0000 (UTC)
Message-Id: <201912241214.xBOCEp6e021539@ceres.dti.ne.jp>
Date: Tue, 24 Dec 2019 21:14:51 +0900 (JST)
From: Izumi Tsutsui <tsutsui@ceres.dti.ne.jp>
Reply-To: tsutsui@ceres.dti.ne.jp
To: gnats-bugs@NetBSD.org
Cc: tsutsui@ceres.dti.ne.jp
Subject: 9.0_RC1 audio(4) malloc failed
X-Send-Pr-Version: 3.95

>Number:         54796
>Category:       kern
>Synopsis:       9.0_RC1 audio(4) malloc failed
>Confidential:   no
>Severity:       critical
>Priority:       medium
>Responsible:    isaki
>State:          closed
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Tue Dec 24 12:20:00 +0000 2019
>Closed-Date:    Sun Jan 12 07:31:57 +0000 2020
>Last-Modified:  Sun Jan 12 07:31:57 +0000 2020
>Originator:     Izumi Tsutsui
>Release:        NetBSD 9.0_RC1
>Organization:
>Environment:
System: NetBSD 9.0_RC1 (GENERIC) #0: Wed Nov 27 16:14:52 UTC 2019 mkrepro@mkrepro.NetBSD.org:/usr/src/sys/arch/i386/compile/GENERIC i386
Architecture: i386
Machine: i386
>Description:
On my NetBSD/i386 9.0_RC1 machine, kernel audio(9) system
gets following failures on heavy load
(firefox + pulseaudio + HTML5 video + build.sh -j4)
and the kernel stalls (some kernel thread never respond):
---
Dec 23 01:07:33 mirage /netbsd: [ 26653.3844655] audio0: malloc outbuf(30720) failed
Dec 23 01:07:33 mirage /netbsd: [ 26653.3844655] audio0: malloc outbuf(30720) failed
Dec 23 01:07:33 mirage /netbsd: [ 26653.3844655] audio0: malloc input(30720) failed
Dec 23 01:07:33 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:07:33 mirage pulseaudio[792]: [oss] oss-util.c: open('/dev/audio'): Cannot allocate memory
Dec 23 01:07:33 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:07:33 mirage pulseaudio[792]: [oss] module-oss.c: Resume failed, device busy (Invalid argument)
Dec 23 01:07:51 mirage /netbsd: [ 26670.5230773] audio0: malloc outbuf(30720) failed
Dec 23 01:07:51 mirage /netbsd: [ 26670.5230773] audio0: malloc outbuf(30720) failed
Dec 23 01:07:51 mirage /netbsd: [ 26670.5230773] audio0: malloc input(30720) failed
Dec 23 01:07:51 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:07:51 mirage pulseaudio[792]: [oss] oss-util.c: open('/dev/audio'): Cannot allocate memory
Dec 23 01:07:51 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:07:51 mirage pulseaudio[792]: [oss] module-oss.c: Resume failed, device busy (Invalid argument)
Dec 23 01:09:21 mirage /netbsd: [ 26760.9984991] audio0: malloc outbuf(30720) failed
Dec 23 01:09:21 mirage /netbsd: [ 26760.9984991] audio0: malloc outbuf(30720) failed
Dec 23 01:09:21 mirage /netbsd: [ 26760.9984991] audio0: audio_track_init_freq: malloc(7680) failed
Dec 23 01:09:21 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:09:21 mirage pulseaudio[792]: [oss] oss-util.c: open('/dev/audio'): Cannot allocate memory
Dec 23 01:09:21 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:09:21 mirage pulseaudio[792]: [oss] module-oss.c: Resume failed, device busy (Invalid argument)
Dec 23 01:13:21 mirage /netbsd: [ 27001.3593118] audio0: malloc outbuf(30720) failed
Dec 23 01:13:21 mirage /netbsd: [ 27001.3593118] audio0: malloc outbuf(30720) failed
Dec 23 01:13:21 mirage /netbsd: [ 27001.3593118] audio0: audio_track_init_freq: malloc(7680) failed
Dec 23 01:13:21 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:13:21 mirage pulseaudio[792]: [oss] oss-util.c: open('/dev/audio'): Cannot allocate memory
Dec 23 01:13:21 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:13:21 mirage pulseaudio[792]: [oss] module-oss.c: Resume failed, device busy (Invalid argument)
Dec 23 01:13:21 mirage /netbsd: [ 27001.3593118] audio0: malloc outbuf(30720) failed
Dec 23 01:13:21 mirage /netbsd: [ 27001.3593118] audio0: malloc outbuf(30720) failed
Dec 23 01:13:21 mirage /netbsd: [ 27001.3593118] audio0: audio_track_init_freq: malloc(7680) failed
Dec 23 01:13:21 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:13:21 mirage pulseaudio[792]: [oss] oss-util.c: open('/dev/audio'): Cannot allocate memory
Dec 23 01:13:21 mirage pulseaudio[792]: [oss] core-error.c: Unable to convert error string to locale, filtering.
Dec 23 01:13:21 mirage pulseaudio[792]: [oss] module-oss.c: Resume failed, device busy (Invalid argument)
---

>How-To-Repeat:
See above.

>Fix:
isaki@ says we could change the following kern_malloc() and
kern_realloc() to use M_NOWAIT to M_WAITOK in src/sys/dev/audio/audio.c:
 https://nxr.netbsd.org/xref/src/sys/dev/audio/audio.c?r=1.33#3067
---
   3067 static void *
   3068 audio_realloc(void *memblock, size_t bytes)
   3069 {
   3070 
   3071 	if (memblock != NULL) {
   3072 		if (bytes != 0) {
   3073 			return kern_realloc(memblock, bytes, M_NOWAIT);
   3074 		} else {
   3075 			kern_free(memblock);
   3076 			return NULL;
   3077 		}
   3078 	} else {
   3079 		if (bytes != 0) {
   3080 			return kern_malloc(bytes, M_NOWAIT);
   3081 		} else {
   3082 			return NULL;
   3083 		}
   3084 	}
   3085 }
---
Izumi Tsutsui

>Release-Note:

>Audit-Trail:
From: "Tetsuya Isaki" <isaki@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/54796 CVS commit: src/sys/dev/audio
Date: Thu, 26 Dec 2019 11:24:55 +0000

 Module Name:	src
 Committed By:	isaki
 Date:		Thu Dec 26 11:24:55 UTC 2019

 Modified Files:
 	src/sys/dev/audio: audio.c

 Log Message:
 Use M_WAITOK instead of M_NOWAIT.
 These allocations don't require NOWAIT constraints.
 Will fix PR kern/54796.


 To generate a diff of this commit:
 cvs rdiff -u -r1.33 -r1.34 src/sys/dev/audio/audio.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

Responsible-Changed-From-To: kern-bug-people->isaki
Responsible-Changed-By: isaki@NetBSD.org
Responsible-Changed-When: Thu, 26 Dec 2019 11:33:22 +0000
Responsible-Changed-Why:


State-Changed-From-To: open->feedback
State-Changed-By: isaki@NetBSD.org
State-Changed-When: Thu, 26 Dec 2019 11:33:22 +0000
State-Changed-Why:
sys/dev/audio/audio.c 1.34 (or later) will fix this problem.
Could you reproduce it?


From: Izumi Tsutsui <tsutsui@ceres.dti.ne.jp>
To: gnats-bugs@netbsd.org
Cc: isaki@netbsd.org, tsutsui@ceres.dti.ne.jp
Subject: Re: kern/54796 (9.0_RC1 audio(4) malloc failed)
Date: Fri, 27 Dec 2019 00:16:05 +0900

 > sys/dev/audio/audio.c 1.34 (or later) will fix this problem.
 > Could you reproduce it?

 With M_WAITOK in audio.c, I no longer see errors and audio playing
 (firefox + nicovideo.jp) works without obvious problem.

 BTW, now I've got another hang with X corruption on load,
 looks caused by memory shortage in radeon drm..
 (even in that case audio worked until actual hang)

 ---
 Dec 25 04:14:54 mirage /netbsd: [ 6011.7988327] kern error: [drm:(../../../../external/bsd/drm2/dist/drm/radeon/radeon_gem.c:84)radeon_gem_object_create] *ERROR* Failed to allocate GEM object (3944448, 2, 4096, -12)
 Dec 25 04:14:54 mirage /netbsd: [ 6011.8388527] kern error: [drm:(../../../../external/bsd/drm2/dist/drm/radeon/radeon_gem.c:84)radeon_gem_object_create] *ERROR* Failed to allocate GEM object (3944448, 2, 4096, -12)
 Dec 25 04:14:54 mirage /netbsd: [ 6011.8788718] kern error: [drm:(../../../../external/bsd/drm2/dist/drm/radeon/radeon_gem.c:84)radeon_gem_object_create] *ERROR* Failed to allocate GEM object (3944448, 2, 4096, -12)
 Dec 25 04:14:54 mirage /netbsd: [ 6011.8988815] kern error: [drm:(../../../../external/bsd/drm2/dist/drm/radeon/radeon_gem.c:84)radeon_gem_object_create] *ERROR* Failed to allocate GEM object (1327104, 2, 4096, -12)
 Dec 25 04:14:54 mirage /netbsd: [ 6011.9188974] kern error: [drm:(../../../../external/bsd/drm2/dist/drm/radeon/radeon_gem.c:84)radeon_gem_object_create] *ERROR* Failed to allocate GEM object (3944448, 2, 4096, -12)
 Dec 25 04:15:17 mirage /netbsd: [ 6034.9801856] kern error: [drm:(../../../../external/bsd/drm2/dist/drm/radeon/radeon_gem.c:84)radeon_gem_object_create] *ERROR* Failed to allocate GEM object (4866048, 2, 4096, -12)

 ---
 Izumi Tsutsui

From: Tetsuya Isaki <isaki@pastel-flower.jp>
To: Izumi Tsutsui <tsutsui@ceres.dti.ne.jp>
Cc: gnats-bugs@netbsd.org
Subject: Re: kern/54796 (9.0_RC1 audio(4) malloc failed)
Date: Fri, 27 Dec 2019 16:20:43 +0900

 At Fri, 27 Dec 2019 00:16:05 +0900,
 Izumi Tsutsui wrote:
 > With M_WAITOK in audio.c, I no longer see errors and audio playing
 > (firefox + nicovideo.jp) works without obvious problem.

 Thank you for confirmation.

 > BTW, now I've got another hang with X corruption on load,
 > looks caused by memory shortage in radeon drm..
 > (even in that case audio worked until actual hang)

 I will close this PR when pullup is done.
 Would you send this as new PR?

 Thanks,
 ---
 Tetsuya Isaki <isaki@pastel-flower.jp / isaki@NetBSD.org>

State-Changed-From-To: feedback->needs-pullups
State-Changed-By: isaki@NetBSD.org
State-Changed-When: Fri, 27 Dec 2019 07:27:05 +0000
State-Changed-Why:
I will pullup it later.


From: Izumi Tsutsui <tsutsui@ceres.dti.ne.jp>
To: isaki@pastel-flower.jp
Cc: gnats-bugs@netbsd.org, tsutsui@ceres.dti.ne.jp
Subject: Re: kern/54796 (9.0_RC1 audio(4) malloc failed)
Date: Fri, 27 Dec 2019 20:40:43 +0900

 > > BTW, now I've got another hang with X corruption on load,
 > > looks caused by memory shortage in radeon drm..
  :
 > I will close this PR when pullup is done.
 > Would you send this as new PR?

 Yes, of course.

 ---
 Izumi Tsutsui

State-Changed-From-To: needs-pullups->pending-pullups
State-Changed-By: isaki@NetBSD.org
State-Changed-When: Tue, 31 Dec 2019 13:03:01 +0000
State-Changed-Why:
netbsd-9 #593


From: "Martin Husemann" <martin@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/54796 CVS commit: [netbsd-9] src/sys/dev/audio
Date: Thu, 2 Jan 2020 09:18:15 +0000

 Module Name:	src
 Committed By:	martin
 Date:		Thu Jan  2 09:18:15 UTC 2020

 Modified Files:
 	src/sys/dev/audio [netbsd-9]: audio.c

 Log Message:
 Pull up following revision(s) (requested by isaki in ticket #593):

 	sys/dev/audio/audio.c: revision 1.34
 	sys/dev/audio/audio.c: revision 1.35

 Use M_WAITOK instead of M_NOWAIT.
 These allocations don't require NOWAIT constraints.

 Will fix PR kern/54796.

  -

 Improve and simplify around audio_realloc().


 To generate a diff of this commit:
 cvs rdiff -u -r1.28.2.4 -r1.28.2.5 src/sys/dev/audio/audio.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

State-Changed-From-To: pending-pullups->closed
State-Changed-By: isaki@NetBSD.org
State-Changed-When: Sun, 12 Jan 2020 07:31:57 +0000
State-Changed-Why:
pulled up. Thanks for reporting.


>Unformatted:

Home	PR Database Search