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:56:09 +0200 (CEST)
On Sun, 25 Jun 2017 17:18+0200, Trond Endrestøl wrote:

> 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.

Partial success! Your patch brought me past the libthr issue with 
/sbin/zfs.

Like the OP, portupgrade (and ruby22) complains about unable to create 
a timer thread. I shall attempt to rebuild lang/ruby22 and 
emulators/virtualbox-ose-additions-nox11. I think I'll switch to 
ruby23 while I'm at it.

-- 
+-------------------------------+------------------------------------+
| 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:56:18 UTC

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