Re: Current amd64 new error or warning from today's current with ruby r320323

From: Trond Endrestøl <Trond.Endrestol_at_fagskolen.gjovik.no>
Date: Sun, 25 Jun 2017 17:18:18 +0200 (CEST)
On Sun, 25 Jun 2017 16:41+0300, Konstantin Belousov wrote:

> On Sat, Jun 24, 2017 at 07:19:25PM -0700, Manfred Antar wrote:
> > 
> > > On Jun 24, 2017, at 7:04 PM, Konstantin Belousov <kostikbel_at_gmail.com> wrote:
> > > 
> > > On Sat, Jun 24, 2017 at 06:48:03PM -0700, Manfred Antar wrote:
> > >> 
> > >>> On Jun 24, 2017, at 6:23 PM, Konstantin Belousov <kostikbel_at_gmail.com> wrote:
> > >>> 
> > >>> On Sat, Jun 24, 2017 at 06:08:50PM -0700, Manfred Antar wrote:
> > >>>> New world and kernel  r320323
> > >>>> I get a new error or message when using ruby:
> > >>>> 
> > >>>> 
> > >>>> /usr/local/sbin/portupgrade -av
> > >>>> <main>: warning: pthread_create failed for timer: Resource temporarily unavailable, scheduling broken
> > >>>> 
> > >>>> everything works just this message when using ruby. I recompiled ruby , still same message
> > >>>> 
> > >>>> /usr/local/bin/ruby -v
> > >>>> <main>: warning: pthread_create failed for timer: Resource temporarily unavailable, scheduling broken
> > >>>> ruby 2.3.4p301 (2017-03-30 revision 58214) [amd64-freebsd12]
> > >>>> 
> > >>>> Not sure what???s changed, I noticed some commits to vm stuff, maybe thats it.
> > >>> 
> > >>> ktrace your failing ruby invocation, then post output of kdump -H somewhere.
> > >>> 
> > >> 
> > >> Ok not sure  if this is right , but this is what i did:
> > >> 
> > >> (tmp)4637}ktrace /usr/local/bin/ruby -v
> > >> <main>: warning: pthread_create failed for timer: Resource temporarily unavailable, scheduling broken
> > >> ruby 2.3.4p301 (2017-03-30 revision 58214) [amd64-freebsd12]
> > >> 
> > >> (tmp)4638}kdump -H -f ./ktrace.out >  kdump.txt
> > >> 
> > >> you can get kdump.txt at:
> > >> 
> > >> http://www.pozo.com/kernel/kdump <http://www.pozo.com/kernel/kdump>.txt
> > >> 
> > >> It???s not failing, I don???t think , I can do portupgrade and it works fine.
> > >> I just get this new message
> > > 
> > > I see what is going on, but it is somewhat strange that it happens.
> > > 
> > > Do you run ruby in a jail with old (say, stable/10) libthr ?
> > > Or do you have environment variable LIBPTHREAD_SPLITSTACK_MAIN set in
> > > your environment ?
> > > 
> > > Anyway, the rework of the stack grow indeed have incompatibility with the
> > > old (pre-11) libthr, which tries to split main thread stack into smaller
> > > stacks for the new threads.  New stack grow code was specifically designed
> > > to prevent this.  Some hack would be needed there, to allow reuse of
> > > the main stack gap.
> > > 
> > 
> > Not running any jails
> > all libraries are current as of today
> > locate libthr. |xargs ls -l
> > -r--r--r--  1 root  wheel  120240 Jun 24 12:50 /lib/libthr.so.3
> > -r--r--r--  1 root  wheel  256072 Jun 24 12:50 /usr/lib/libthr.a
> > lrwxr-xr-x  1 root  wheel      21 Jun 24 12:50 /usr/lib/libthr.so -> ../../lib/libthr.so.3
> > 
> > ldd /usr/local/bin/ruby
> > -rwxr-xr-x  1 root  wheel  2677552 Jun 24 18:22 /usr/local/lib/libruby23.so.2
> > -rwxr-xr-x  1 root  wheel  43832 Jun 24 19:10 /usr/local/lib/libunwind.so.8.0.1
> > 
> > /usr/local/bin/ruby:
> > 	libruby23.so.23 => /usr/local/lib/libruby23.so.23 (0x800a00000)
> > 	libelf.so.2 => /lib/libelf.so.2 (0x800e9d000)
> > 	libunwind.so.8 => /usr/local/lib/libunwind.so.8 (0x8010b5000)
> > 	libexecinfo.so.1 => /usr/lib/libexecinfo.so.1 (0x8012ce000)
> > 	libprocstat.so.1 => /usr/lib/libprocstat.so.1 (0x8014d1000)
> > 	libcrypt.so.5 => /lib/libcrypt.so.5 (0x8016db000)
> > 	libm.so.5 => /lib/libm.so.5 (0x8018f9000)
> > 	libthr.so.3 => /lib/libthr.so.3 (0x801b26000)
> > 	libc.so.7 => /lib/libc.so.7 (0x801d4e000)
> > 	libgcc_s.so.1 => /lib/libgcc_s.so.1 (0x802335000)
> > 	liblzma.so.5 => /usr/lib/liblzma.so.5 (0x80254b000)
> > 	libkvm.so.7 => /lib/libkvm.so.7 (0x802774000)
> > 	libutil.so.9 => /lib/libutil.so.9 (0x802982000)
> > 
> > no LIBPTHREAD_SPLITSTACK_MAIN set anywhere
> > 
> > This is a fresh buildworld - installworld from noon today California time.
> > 
> > here are env in make.conf:
> > DEFAULT_VERSIONS= mysql=5.7 apache=2.4 python2=2.7 python3=3.4 ruby=2.3 perl5=5.24 php=5.6 tcltk=8.6 samba=4.4 ssl=base ncurses=base
> > MALLOC_PRODUCTION=yes
> > WITH_BDB_VERSION=5
> > 
> > env in src.conf:
> > WITHOUT_DYNAMICROOT=yes 
> > WITHOUT_UNBOUND=yes
> > WITHOUT_CASPER=yes
> > WITHOUT_CAPSICUM=yes
> > WITHOUT_DMAGENT=yes
> > WITHOUT_PROFILE=yes
> > WITHOUT_TESTS=yes
> > WITHOUT_KERNEL_SYMBOLS=yes
> > WITHOUT_DEBUG_FILES=1
> > WITHOUT_LIB32=yes
> > INSTALL_NODEBUG=yes
> > 
> > # Don't die on warnings
> > NO_WERROR=
> > WERROR=
> > KERNCONF=pozo
> > WITH_CCACHE_BUILD=yes
> 
> Weird, I do not see where such behaviour could come from.  I mean,
> the behaviour of the libthr, assuming that the failing call is from
> libthr and not from the ruby.
> 
> Anyway, please try the following.  Note that this might be not the final
> fix, but I am interesting in seeing whether it fixed the issue for you.
> I want to see the kdump output from ktrace _without_ -di, same as in 
> your first trace.
> 
> diff --git a/lib/libc/sys/mprotect.2 b/lib/libc/sys/mprotect.2
> index 3be81c6582a..ca4d6307c44 100644
> --- a/lib/libc/sys/mprotect.2
> +++ b/lib/libc/sys/mprotect.2
> _at__at_ -28,7 +28,7 _at__at_
>  .\"	_at_(#)mprotect.2	8.1 (Berkeley) 6/9/93
>  .\" $FreeBSD$
>  .\"
> -.Dd August 3, 2016
> +.Dd June 24, 2017
>  .Dt MPROTECT 2
>  .Os
>  .Sh NAME
> _at__at_ -80,10 +80,24 _at__at_ and
>  arguments is not valid.
>  .It Bq Er EACCES
>  The calling process was not allowed to change
> -the protection to the value specified by
> -the
> +the protection to the value specified by the
>  .Fa prot
>  argument.
> +.It Bq Er ENOMEM
> +The virtual address range specified by the
> +.Fa addr
> +and
> +.Fa len
> +arguments specify one or more pages which are not mapped.
> +.It Bq Er ENOMEM
> +The
> +.Fa prot
> +argument specifies
> +.Dv PROT_WRITE
> +on a
> +.Dv MAP_PRIVATE
> +mapping, and it would require more swap space than the system is able to
> +supply for the private pages.
>  .El
>  .Sh SEE ALSO
>  .Xr madvise 2 ,
> diff --git a/sys/vm/vm_map.c b/sys/vm/vm_map.c
> index 39cf303eaa0..b311b54d0f0 100644
> --- a/sys/vm/vm_map.c
> +++ b/sys/vm/vm_map.c
> _at__at_ -1490,11 +1490,11 _at__at_ vm_map_fixed(vm_map_t map, vm_object_t object, vm_ooffset_t offset,
>   *	If object is non-NULL, ref count must be bumped by caller
>   *	prior to making call to account for the new entry.
>   */
> -int
> -vm_map_find(vm_map_t map, vm_object_t object, vm_ooffset_t offset,
> -	    vm_offset_t *addr,	/* IN/OUT */
> -	    vm_size_t length, vm_offset_t max_addr, int find_space,
> -	    vm_prot_t prot, vm_prot_t max, int cow)
> +static int
> +vm_map_find1(vm_map_t map, vm_object_t object, vm_ooffset_t offset,
> +    vm_offset_t *addr,	/* IN/OUT */
> +    vm_size_t length, vm_offset_t max_addr, int find_space, vm_prot_t prot,
> +    vm_prot_t max, int cow)
>  {
>  	vm_offset_t alignment, initial_addr, start;
>  	int result;
> _at__at_ -1556,6 +1556,26 _at__at_ again:
>  	return (result);
>  }
>  
> +int
> +vm_map_find(vm_map_t map, vm_object_t object, vm_ooffset_t offset,
> +    vm_offset_t *addr,	/* IN/OUT */
> +    vm_size_t length, vm_offset_t max_addr, int find_space, vm_prot_t prot,
> +    vm_prot_t max, int cow)
> +{
> +	int rv;
> +	bool hinted;
> +
> +	hinted = *addr != 0;
> +	for (;;) {
> +		rv = vm_map_find1(map, object, offset, addr, length, max_addr,
> +		    find_space, prot, max, cow);
> +		if (rv != KERN_NO_SPACE || !hinted)
> +			return (rv);
> +		*addr = 0;
> +		hinted = false;
> +	}
> +}
> +
>  /*
>   *	vm_map_simplify_entry:
>   *
> _at__at_ -1970,7 +1990,7 _at__at_ vm_map_pmap_enter(vm_map_t map, vm_offset_t addr, vm_prot_t prot,
>   */
>  int
>  vm_map_protect(vm_map_t map, vm_offset_t start, vm_offset_t end,
> -	       vm_prot_t new_prot, boolean_t set_max)
> +    vm_prot_t new_prot, boolean_t set_max)
>  {
>  	vm_map_entry_t current, entry;
>  	vm_object_t obj;
> _at__at_ -1995,7 +2015,8 _at__at_ vm_map_protect(vm_map_t map, vm_offset_t start, vm_offset_t end,
>  	if (vm_map_lookup_entry(map, start, &entry)) {
>  		vm_map_clip_start(map, entry, start);
>  	} else {
> -		entry = entry->next;
> +		vm_map_unlock(map);
> +		return (KERN_INVALID_ADDRESS);
>  	}
>  
>  	/*
> _at__at_ -2003,6 +2024,8 _at__at_ vm_map_protect(vm_map_t map, vm_offset_t start, vm_offset_t end,
>  	 */
>  	for (current = entry; current != &map->header && current->start < end;
>  	    current = current->next) {
> +		if ((current->eflags & MAP_ENTRY_GUARD) != 0)
> +			continue;
>  		if (current->eflags & MAP_ENTRY_IS_SUB_MAP) {
>  			vm_map_unlock(map);
>  			return (KERN_INVALID_ARGUMENT);
> _at__at_ -2011,6 +2034,11 _at__at_ vm_map_protect(vm_map_t map, vm_offset_t start, vm_offset_t end,
>  			vm_map_unlock(map);
>  			return (KERN_PROTECTION_FAILURE);
>  		}
> +		if (current->end < end && (current->next == &map->header ||
> +		    current->next->start > current->end)) {
> +			vm_map_unlock(map);
> +			return (KERN_INVALID_ADDRESS);
> +		}
>  	}
>  
>  	/*
> _at__at_ -2712,9 +2740,9 _at__at_ vm_map_wire(vm_map_t map, vm_offset_t start, vm_offset_t end,
>  		 * If VM_MAP_WIRE_HOLESOK was specified, skip this check.
>  		 */
>  	next_entry:
> -		if (((flags & VM_MAP_WIRE_HOLESOK) == 0) &&
> -		    (entry->end < end && (entry->next == &map->header ||
> -		    entry->next->start > entry->end))) {
> +		if ((flags & VM_MAP_WIRE_HOLESOK) == 0 &&
> +		    entry->end < end && (entry->next == &map->header ||
> +		    entry->next->start > entry->end)) {
>  			end = entry->end;
>  			rv = KERN_INVALID_ADDRESS;
>  			goto done;
> diff --git a/sys/vm/vm_mmap.c b/sys/vm/vm_mmap.c
> index 4d8f6ad9ed7..09912250d52 100644
> --- a/sys/vm/vm_mmap.c
> +++ b/sys/vm/vm_mmap.c
> _at__at_ -607,6 +607,7 _at__at_ kern_mprotect(struct thread *td, uintptr_t addr0, size_t size, int prot)
>  	case KERN_PROTECTION_FAILURE:
>  		return (EACCES);
>  	case KERN_RESOURCE_SHORTAGE:
> +	case KERN_INVALID_ADDRESS:
>  		return (ENOMEM);
>  	}
>  	return (EINVAL);

I'm seeing similar fallout on r320327, built from scratch while 
running r320293:

Script started on Sun Jun 25 17:03:41 2017
# uname -aKU
FreeBSD  12.0-CURRENT FreeBSD 12.0-CURRENT #0 r320327: Sun Jun 25 16:35:02 CEST 2017     root_at_freebsd-head-uefi-zfs.bsd.net:/usr/obj/usr/src/sys/VBOX  amd64 1200035 1200035
# /sbin/zfs mount -va
Fatal error 'Cannot allocate red zone for initial thread' at line 392 in file /usr/src/lib/libthr/thread/thr_init.c (errno = 12)
Abort trap (core dumped)
# ls -l /lib/libthr*
-r--r--r--  1 root  wheel  153336 Jun 25 16:39 /lib/libthr.so.3
# ls -l /usr/lib/libthr*
-r--r--r--  1 root  wheel  256064 May 28 21:41 /usr/lib/libthr.a
lrwxr-xr-x  1 root  wheel      21 Jun 25 16:39 /usr/lib/libthr.so -> ../../lib/libthr.so.3
-r--r--r--  1 root  wheel  270362 May 28 21:41 /usr/lib/libthr_p.a
-r--r--r--  1 root  wheel   45376 Apr 22 10:39 /usr/lib/libthread_db.a
lrwxr-xr-x  1 root  wheel      17 Jun 25 16:39 /usr/lib/libthread_db.so -> libthread_db.so.3
-r--r--r--  1 root  wheel   38776 Jun 25 16:39 /usr/lib/libthread_db.so.3
-r--r--r--  1 root  wheel   49496 Apr 22 10:39 /usr/lib/libthread_db_p.a
# ldd /sbin/zfs
/sbin/zfs:
	libjail.so.1 => /lib/libjail.so.1 (0x800247000)
	libnvpair.so.2 => /lib/libnvpair.so.2 (0x80024f000)
	libuutil.so.2 => /lib/libuutil.so.2 (0x800269000)
	libzfs_core.so.2 => /lib/libzfs_core.so.2 (0x800276000)
	libzfs.so.3 => /lib/libzfs.so.3 (0x800281000)
	libc.so.7 => /lib/libc.so.7 (0x8002cd000)
	libmd.so.6 => /lib/libmd.so.6 (0x8006d1000)
	libumem.so.2 => /lib/libumem.so.2 (0x8006eb000)
	libutil.so.9 => /lib/libutil.so.9 (0x8006f0000)
	libm.so.5 => /lib/libm.so.5 (0x800706000)
	libavl.so.2 => /lib/libavl.so.2 (0x800736000)
	libbsdxml.so.4 => /lib/libbsdxml.so.4 (0x80073a000)
	libgeom.so.5 => /lib/libgeom.so.5 (0x800770000)
	libz.so.6 => /lib/libz.so.6 (0x800779000)
	libthr.so.3 => /lib/libthr.so.3 (0x800793000)
	libsbuf.so.6 => /lib/libsbuf.so.6 (0x8007bd000)
# ls -l /sbin/zfs
-r-xr-xr-x  1 root  wheel  124296 Jun 25 16:39 /sbin/zfs
# exit

Script done on Sun Jun 25 17:04:32 2017

Although not relevant for this case, neither /usr/lib/libthr.a, nor 
/usr/lib/libthr_p.a, nor /usr/lib/libthread_db.a, nor 
/usr/lib/libthread_db_p.a has been updated by installworld, nor 
removed by delete-old-libs, in a very long time.

Anything else I can contribute? I'll try your patch and see if I can 
get any further.

-- 
+-------------------------------+------------------------------------+
| Vennlig hilsen,               | Best regards,                      |
| Trond Endrestøl,              | Trond Endrestøl,                   |
| IT-ansvarlig,                 | System administrator,              |
| Fagskolen Innlandet,          | Gjøvik Technical College, Norway,  |
| tlf. mob.   952 62 567,       | Cellular...: +47 952 62 567,       |
| sentralbord 61 14 54 00.      | Switchboard: +47 61 14 54 00.      |
+-------------------------------+------------------------------------+
Received on Sun Jun 25 2017 - 13:18:30 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:41:12 UTC