[Date Prev][Date Next] [Chronological] [Thread] [Top]

(ITS#3400) loop in slapd_daemon_task() (daemon.c) after repeated EBADF returns from select()



Full_Name: Chris Markle
Version: 2.1 (but this applies to 2.2 as well)
OS: Solaris
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (63.211.143.38)


This was observed on 2.1.x on Solaris (where select is mapped to poll) but
looking at the code strongly suggests that it's an issue on 2.2.x as well.
Net-net, there is something else going on that causes a closed FD to be included
in the fdset's passed to select such that select returns -1 and errno=EBADF. If
you look at the code there's this theory that 16 of those in a row should result
in a shut-down of slapd, but since the ebadf counter is being intialized to zero
in the loop: 

	while ( !slapd_shutdown ) {
                [...]
#define SLAPD_EBADF_LIMIT 16
		int ebadf = 0;
                [...]
        }

(as opposed to outside the loop) then the counter will never get to 16, slapd
will never shutdown and it will spin.

As to why this closed FD is getting in the select set I have no idea. We cannot
repro this at all and only have core file and truss output (a customer ran 140
days and then had this happen - they were not logging anything). I will attach
truss output to bottom for ref sake. Anyway at minimum, the defintion of ebadf
counter should be made outside the loop and it should be init'ed to zero before
going into the loop. At least this would shutdown slapd upon this error and not
spin. This is any easy "fix".

Truss for a few passes through the loop follows... You will notice in here that
select() gets mapped to select_large_fdset() since we are using more than 1024
descriptors and then mapped to poll(). One of the FDs in the poll() return shows
"fd=28 ev=POLLRDNORM rev=POLLNVAL" which indicates that the fd=28 is invlaid
(closed?). Presumably this maps to EBADF for select(). Etc. etc. Here goes:

Base time stamp:  1100519931.9802  [ Mon Nov 15 20:58:51 JST 2004 ]
[...]
14442/2@2:	 1.1344	  -> libc:time(0x0, 0x660, 0x218bc, 0x62d4c)
14442/2:	 1.1346	time() = 1100519933
14442/2@2:	 1.1347	  -> libc_psr:memset(0xd2fff774, 0x0, 0x400, 0x62d4c)
14442/2@2:	 1.1349	  -> libc_psr:memset(0xd2fffb74, 0x0, 0x400, 0xfffffff8)
14442/2@2:	 1.1351	  -> ldap_pvt_thread_mutex_lock(0x4dfd40, 0x0, 0xffffffff,
0xfffffff8)
14442/2@2:	 1.1354	    -> libthread:mutex_lock(0x4dfd40, 0x0, 0x0, 0x0)
14442/2@2:	 1.1356	    <- libthread:mutex_lock() = 0
14442/2@2:	 1.1358	  -> libc_psr:memmove(0xd2fffb74, 0x4e0160, 0x400,
0xfffffff8)
14442/2@2:	 1.1360	  -> libc_psr:memcpy(0xd2fffb74, 0x4e0160, 0x400,
0xfffffff8)
14442/2@2:	 1.1362	  -> libc_psr:memmove(0xd2fff774, 0x4e0560, 0x400, 0x0)
14442/2@2:	 1.1365	  -> libc_psr:memcpy(0xd2fff774, 0x4e0560, 0x400, 0x0)
14442/2@2:	 1.1367	  -> ldap_pvt_thread_mutex_unlock(0x4dfd40, 0x4e0960, 0x0,
0x0)
14442/2@2:	 1.1369	    -> libthread:mutex_unlock(0x4dfd40, 0x0, 0x0, 0x0)
14442/2@2:	 1.1372	    <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1375	  -> ldap_pvt_thread_pool_backload(0x4f4410, 0x4e0960, 0x0,
0x0)
14442/2@2:	 1.1377	    -> ldap_pvt_thread_mutex_lock(0x4f9958, 0x0, 0x0, 0x0)
14442/2@2:	 1.1379	      -> libthread:mutex_lock(0x4f9958, 0x0, 0x0, 0x0)
14442/2@2:	 1.1382	      <- libthread:mutex_lock() = 0
14442/2@2:	 1.1384	    <- ldap_pvt_thread_mutex_lock() = 0
14442/2@2:	 1.1386	    -> ldap_pvt_thread_mutex_unlock(0x4f9958, 0x0, 0x0, 0x0)
14442/2@2:	 1.1388	      -> libthread:mutex_unlock(0x4f9958, 0x0, 0x0, 0x0)
14442/2@2:	 1.1390	      <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1392	    <- ldap_pvt_thread_mutex_unlock() = 0
14442/2@2:	 1.1394	  <- libc:_poll() = 1627
14442/2@2:	 1.1396	  -> libc:select_large_fdset(0x65b, 0xd2fffb74, 0xd2fff774,
0x0)
14442/2@2:	 1.1399	    -> libc_psr:memset(0xd2ffd188, 0x0, 0x2000, 0x0)
14442/2@2:	 1.1401	    <- libc_psr:memset() = 0xd2ffd188
14442/2@2:	 1.1404	    -> libc_psr:memset(0xd2ffcf80, 0x0, 0x200, 0xfffffff8)
14442/2@2:	 1.1406	    <- libc_psr:memset() = 0xd2ffcf80
14442/2@2:	 1.1408	    -> libc:realloc_fds(0xd2ffd184, 0xd2ffd180, 0xd2ffcf80,
0xfffffff8)
14442/2@2:	 1.1411	      -> libc:malloc(0x400, 0x0, 0x0, 0x0)
14442/2@2:	 1.1413	        -> libthread:mutex_lock(0xff1c05a0, 0x754a8, 0x0,
0xff1bc000)
14442/2@2:	 1.1416	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.1418	        -> libc:_malloc_unlocked(0x400, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1420	          -> libc:realfree(0x5409f498, 0xbf9, 0x1000,
0x1000)
14442/2@2:	 1.1423	            -> libc:t_delete(0x540a0090, 0x13c040, 0xbf8,
0x246bdaa8)
14442/2@2:	 1.1426	              -> libc:t_splay(0x540a0090, 0x749b4, 0x0, 0x0)
14442/2@2:	 1.1428	              <- libc:t_splay() = 0
14442/2@2:	 1.1430	            <- libc:t_delete() = 0x540a0090
14442/2@2:	 1.1432	          <- libc:realfree() = 0x5409f498
14442/2@2:	 1.1434	        <- libc:_malloc_unlocked() = 0x5409f090
14442/2@2:	 1.1436	        -> libthread:mutex_unlock(0xff1c05a0, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1439	        <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1440	      <- libc:malloc() = 0x5409f090
14442/2@2:	 1.1442	      -> libc_psr:memset(0x5409f090, 0x0, 0x400, 0x0)
14442/2@2:	 1.1445	      <- libc_psr:memset() = 0x5409f090
14442/2@2:	 1.1447	      -> libc_psr:memcpy(0x5409f090, 0xd2ffcf80, 0x200,
0xfffffff8)
14442/2@2:	 1.1449	      <- libc_psr:memcpy() = 0x5409f090
14442/2@2:	 1.1451	    <- libc:realloc_fds() = 0x5409f290
14442/2@2:	 1.1453	    -> libc:realloc_fds(0xd2ffd184, 0xd2ffd180, 0xd2ffcf80,
0xfffffff8)
14442/2@2:	 1.1456	      -> libc:malloc(0x800, 0x0, 0x0, 0x0)
14442/2@2:	 1.1458	        -> libthread:mutex_lock(0xff1c05a0, 0x754a8, 0x0,
0xff1bc000)
14442/2@2:	 1.1460	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.1462	        -> libc:_malloc_unlocked(0x800, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1464	          -> libc:cleanfree(0x0, 0x1, 0x0, 0xff1bc000)
14442/2@2:	 1.1467	            -> libc:realfree(0x2db915c8, 0x744f8, 0x0,
0xff1bc000)
14442/2@2:	 1.1469	            <- libc:realfree() = 0x2db915c8
14442/2@2:	 1.1471	          <- libc:cleanfree() = 0
14442/2@2:	 1.1474	          -> libc:t_delete(0x2db915c0, 0x800, 0x246bdaa8,
0xff1bc000)
14442/2@2:	 1.1476	            -> libc:t_splay(0x2db915c0, 0x749b4, 0x0, 0x0)
14442/2@2:	 1.1479	            <- libc:t_splay() = 0x506746e0
14442/2@2:	 1.1480	          <- libc:t_delete() = 0x2db915c0
14442/2@2:	 1.1482	        <- libc:_malloc_unlocked() = 0x2db915c8
14442/2@2:	 1.1484	        -> libthread:mutex_unlock(0xff1c05a0, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1486	        <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1489	      <- libc:malloc() = 0x2db915c8
14442/2@2:	 1.1490	      -> libc_psr:memset(0x2db915c8, 0x0, 0x800, 0x0)
14442/2@2:	 1.1493	      <- libc_psr:memset() = 0x2db915c8
14442/2@2:	 1.1494	      -> libc_psr:memcpy(0x2db915c8, 0x5409f090, 0x400,
0xfffffff8)
14442/2@2:	 1.1497	      <- libc_psr:memcpy() = 0x2db915c8
14442/2@2:	 1.1499	      -> libc:free(0x5409f090, 0x5409f490, 0x0, 0xfffffff8)
14442/2@2:	 1.1501	        -> libthread:mutex_lock(0xff1c05a0, 0x745f0, 0x0,
0xff1bc000)
14442/2@2:	 1.1503	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.1505	        -> libc:_free_unlocked(0x5409f090, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1508	        <- libc:_free_unlocked() = 0x5409f090
14442/2@2:	 1.1511	      -> libthread:mutex_unlock(0xff1c05a0, 0x5409f490, 0x0,
0xfffffff8)
14442/2@2:	 1.1516	      <- libc:free() = 0
14442/2@2:	 1.1520	    <- libc:realloc_fds() = 0x2db919c8
14442/2@2:	 1.1523	    -> libc:realloc_fds(0xd2ffd184, 0xd2ffd180, 0xd2ffcf80,
0xfffffff8)
14442/2@2:	 1.1528	      -> libc:malloc(0x1000, 0x0, 0x0, 0x0)
14442/2@2:	 1.1533	        -> libthread:mutex_lock(0xff1c05a0, 0x754a8, 0x0,
0xff1bc000)
14442/2@2:	 1.1536	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.1538	        -> libc:_malloc_unlocked(0x1000, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1541	          -> libc:cleanfree(0x0, 0x1, 0xff1c283c, 0x400)
14442/2@2:	 1.1544	            -> libc:realfree(0x5409f090, 0x744f8, 0x0,
0xff1bc000)
14442/2@2:	 1.1549	              -> libc:t_delete(0x5409f490, 0x13cc40, 0x400,
0x4216a350)
14442/2@2:	 1.1552	                -> libc:t_splay(0x5409f490, 0x749b4, 0x0,
0x0)
14442/2@2:	 1.1554	                <- libc:t_splay() = 0
14442/2@2:	 1.1557	              <- libc:t_delete() = 0x5409f490
14442/2@2:	 1.1561	            <- libc:realfree() = 0x5409f090
14442/2@2:	 1.1564	          <- libc:cleanfree() = 0
14442/2@2:	 1.1567	          -> libc:t_delete(0x5409f088, 0x13d048, 0x246bdaa8,
0x400)
14442/2@2:	 1.1569	            -> libc:t_splay(0x5409f088, 0x749b4, 0x0, 0x0)
14442/2@2:	 1.1573	            <- libc:t_splay() = 0
14442/2@2:	 1.1576	          <- libc:t_delete() = 0x5409f088
14442/2@2:	 1.1580	          -> libc:realfree(0x540a0098, 0x13c041, 0x13d048,
0x400)
14442/2@2:	 1.1585	          <- libc:realfree() = 0x540a0098
14442/2@2:	 1.1590	        <- libc:_malloc_unlocked() = 0x5409f090
14442/2@2:	 1.1594	        -> libthread:mutex_unlock(0xff1c05a0, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1597	        <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1600	      <- libc:malloc() = 0x5409f090
14442/2@2:	 1.1605	      -> libc_psr:memset(0x5409f090, 0x0, 0x1000, 0x0)
14442/2@2:	 1.1609	      <- libc_psr:memset() = 0x5409f090
14442/2@2:	 1.1612	      -> libc_psr:memcpy(0x5409f090, 0x2db915c8, 0x800,
0xfffffff8)
14442/2@2:	 1.1615	      <- libc_psr:memcpy() = 0x5409f090
14442/2@2:	 1.1618	      -> libc:free(0x2db915c8, 0x2db91dc8, 0x0, 0xfffffff8)
14442/2@2:	 1.1622	        -> libthread:mutex_lock(0xff1c05a0, 0x745f0, 0x0,
0xff1bc000)
14442/2@2:	 1.1633	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.1636	        -> libc:_free_unlocked(0x2db915c8, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1638	        <- libc:_free_unlocked() = 0x2db915c8
14442/2@2:	 1.1642	      -> libthread:mutex_unlock(0xff1c05a0, 0x2db91dc8, 0x0,
0xfffffff8)
14442/2@2:	 1.1646	      <- libc:free() = 0
14442/2@2:	 1.1650	    <- libc:realloc_fds() = 0x5409f890
14442/2@2:	 1.1653	    -> libc:_poll(0x5409f090, 0x102, 0xffffffff, 0xfffffff8)
14442/2:	 1.1669	poll(0x5409F090, 258, -1)			= 220
14442/2:		fd=4  ev=POLLRDNORM rev=0
14442/2:		fd=6  ev=POLLRDNORM rev=0
14442/2:		fd=7  ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=8  ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=10 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=13 ev=POLLRDNORM rev=0
14442/2:		fd=15 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=17 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=18 ev=POLLRDNORM rev=0
14442/2:		fd=19 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=20 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=21 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=22 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=23 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=24 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=25 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=26 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=27 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=28 ev=POLLRDNORM rev=POLLNVAL
14442/2:		fd=29 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=30 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=31 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=33 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=34 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=35 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=36 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=37 ev=POLLRDNORM rev=0
14442/2:		fd=38 ev=POLLRDNORM rev=0
14442/2:		fd=40 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=41 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=42 ev=POLLRDNORM rev=0
14442/2:		fd=43 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		...skipping 226 file descriptors...
14442/2@2:	 1.1677	    <- libc:_poll() = 220
14442/2@2:	 1.1683	    -> libc:___errno(0x20, 0x5409f090, 0xef, 0x5409f128)
14442/2@2:	 1.1686	      -> libthread:thr_main(0x0, 0x2433c, 0x0, 0x0)
14442/2@2:	 1.1690	      <- libthread:thr_main() = 0
14442/2@2:	 1.1693	    -> libc:thr_errnop(0x4e4650, 0x5409f090, 0xef,
0x5409f128)
14442/2@2:	 1.1696	    -> libthread:_thr_errnop(0xff0da574, 0x5409f090, 0x218bc,
0xff152a58)
14442/2@2:	 1.1706	    <- libc:___errno() = 0xff0c0270
14442/2@2:	 1.1709	    -> libc:free(0x5409f090, 0x5409f090, 0x218bc,
0xff152a58)
14442/2@2:	 1.1712	      -> libthread:mutex_lock(0xff1c05a0, 0x745f0, 0x0,
0xff1bc000)
14442/2@2:	 1.1715	      <- libthread:mutex_lock() = 0
14442/2@2:	 1.1718	      -> libc:_free_unlocked(0x5409f090, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1720	      <- libc:_free_unlocked() = 0x5409f090
14442/2@2:	 1.1722	    -> libthread:mutex_unlock(0xff1c05a0, 0x5409f090,
0x218bc, 0xff152a58)
14442/2@2:	 1.1725	    <- libc:free() = 0
14442/2@2:	 1.1728	  <- libc:select_large_fdset() = -1
14442/2@2:	 1.1730	  -> libc:___errno(0xffffffff, 0x660, 0xd2fff774, 0x0)
14442/2@2:	 1.1734	    -> libthread:thr_main(0x0, 0x2433c, 0x0, 0x0)
14442/2@2:	 1.1737	    <- libthread:thr_main() = 0
14442/2@2:	 1.1741	  -> libc:thr_errnop(0x4e4650, 0x660, 0xd2fff774, 0x0)
14442/2@2:	 1.1744	  -> libthread:_thr_errnop(0xff0da574, 0x660, 0x218bc,
0x62d4c)
14442/2@2:	 1.1746	  <- libc:___errno() = 0xff0c0270
14442/2@2:	 1.1749	  -> libc:time(0x0, 0x660, 0x218bc, 0x62d4c)
14442/2:	 1.1752	time()						= 1100519933
14442/2@2:	 1.1753	  <- libc:time() = 0x419899fd
14442/2@2:	 1.1756	  -> libc_psr:memset(0xd2fff774, 0x0, 0x400, 0x62d4c)
14442/2@2:	 1.1760	  <- libc_psr:memset() = 0xd2fff774
14442/2@2:	 1.1762	  -> libc_psr:memset(0xd2fffb74, 0x0, 0x400, 0xfffffff8)
14442/2@2:	 1.1766	  <- libc_psr:memset() = 0xd2fffb74
14442/2@2:	 1.1769	  -> ldap_pvt_thread_mutex_lock(0x4dfd40, 0x0, 0xffffffff,
0xfffffff8)
14442/2@2:	 1.1772	    -> libthread:mutex_lock(0x4dfd40, 0x0, 0x0, 0x0)
14442/2@2:	 1.1775	    <- libthread:mutex_lock() = 0
14442/2@2:	 1.1778	  <- ldap_pvt_thread_mutex_lock() = 0
14442/2@2:	 1.1781	  -> libc_psr:memmove(0xd2fffb74, 0x4e0160, 0x400,
0xfffffff8)
14442/2@2:	 1.1784	  -> libc_psr:memcpy(0xd2fffb74, 0x4e0160, 0x400,
0xfffffff8)
14442/2@2:	 1.1787	  <- libc_psr:memmove() = 0xd2fffb74
14442/2@2:	 1.1789	  -> libc_psr:memmove(0xd2fff774, 0x4e0560, 0x400, 0x0)
14442/2@2:	 1.1792	  -> libc_psr:memcpy(0xd2fff774, 0x4e0560, 0x400, 0x0)
14442/2@2:	 1.1795	  <- libc_psr:memmove() = 0xd2fff774
14442/2@2:	 1.1799	  -> ldap_pvt_thread_mutex_unlock(0x4dfd40, 0x4e0960, 0x0,
0x0)
14442/2@2:	 1.1803	    -> libthread:mutex_unlock(0x4dfd40, 0x0, 0x0, 0x0)
14442/2@2:	 1.1805	    <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1807	  <- ldap_pvt_thread_mutex_unlock() = 0
14442/2@2:	 1.1810	  -> ldap_pvt_thread_pool_backload(0x4f4410, 0x4e0960, 0x0,
0x0)
14442/2@2:	 1.1813	    -> ldap_pvt_thread_mutex_lock(0x4f9958, 0x0, 0x0, 0x0)
14442/2@2:	 1.1817	      -> libthread:mutex_lock(0x4f9958, 0x0, 0x0, 0x0)
14442/2@2:	 1.1819	      <- libthread:mutex_lock() = 0
14442/2@2:	 1.1822	    <- ldap_pvt_thread_mutex_lock() = 0
14442/2@2:	 1.1825	    -> ldap_pvt_thread_mutex_unlock(0x4f9958, 0x0, 0x0, 0x0)
14442/2@2:	 1.1827	      -> libthread:mutex_unlock(0x4f9958, 0x0, 0x0, 0x0)
14442/2@2:	 1.1830	      <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1833	    <- ldap_pvt_thread_mutex_unlock() = 0
14442/2@2:	 1.1837	  <- ldap_pvt_thread_pool_backload() = 0
14442/2@2:	 1.1844	  -> libc:select_large_fdset(0x65b, 0xd2fffb74, 0xd2fff774,
0x0)
14442/2@2:	 1.1848	    -> libc_psr:memset(0xd2ffd188, 0x0, 0x2000, 0x0)
14442/2@2:	 1.1853	    <- libc_psr:memset() = 0xd2ffd188
14442/2@2:	 1.1857	    -> libc_psr:memset(0xd2ffcf80, 0x0, 0x200, 0xfffffff8)
14442/2@2:	 1.1861	    <- libc_psr:memset() = 0xd2ffcf80
14442/2@2:	 1.1865	    -> libc:realloc_fds(0xd2ffd184, 0xd2ffd180, 0xd2ffcf80,
0xfffffff8)
14442/2@2:	 1.1868	      -> libc:malloc(0x400, 0x0, 0x0, 0x0)
14442/2@2:	 1.1870	        -> libthread:mutex_lock(0xff1c05a0, 0x754a8, 0x0,
0xff1bc000)
14442/2@2:	 1.1874	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.1877	        -> libc:_malloc_unlocked(0x400, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1881	          -> libc:realfree(0x5409f498, 0xbf9, 0x1000,
0x1000)
14442/2@2:	 1.1884	            -> libc:t_delete(0x540a0090, 0x13c040, 0xbf8,
0x246bdaa8)
14442/2@2:	 1.1887	              -> libc:t_splay(0x540a0090, 0x749b4, 0x0, 0x0)
14442/2@2:	 1.1890	              <- libc:t_splay() = 0
14442/2@2:	 1.1893	            <- libc:t_delete() = 0x540a0090
14442/2@2:	 1.1895	          <- libc:realfree() = 0x5409f498
14442/2@2:	 1.1898	        <- libc:_malloc_unlocked() = 0x5409f090
14442/2@2:	 1.1900	        -> libthread:mutex_unlock(0xff1c05a0, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1903	        <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1906	      <- libc:malloc() = 0x5409f090
14442/2@2:	 1.1909	      -> libc_psr:memset(0x5409f090, 0x0, 0x400, 0x0)
14442/2@2:	 1.1911	      <- libc_psr:memset() = 0x5409f090
14442/2@2:	 1.1914	      -> libc_psr:memcpy(0x5409f090, 0xd2ffcf80, 0x200,
0xfffffff8)
14442/2@2:	 1.1917	      <- libc_psr:memcpy() = 0x5409f090
14442/2@2:	 1.1919	    <- libc:realloc_fds() = 0x5409f290
14442/2@2:	 1.1922	    -> libc:realloc_fds(0xd2ffd184, 0xd2ffd180, 0xd2ffcf80,
0xfffffff8)
14442/2@2:	 1.1925	      -> libc:malloc(0x800, 0x0, 0x0, 0x0)
14442/2@2:	 1.1937	        -> libthread:mutex_lock(0xff1c05a0, 0x754a8, 0x0,
0xff1bc000)
14442/2@2:	 1.1945	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.1950	        -> libc:_malloc_unlocked(0x800, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1955	          -> libc:cleanfree(0x0, 0x1, 0x0, 0xff1bc000)
14442/2@2:	 1.1959	            -> libc:realfree(0x2db915c8, 0x744f8, 0x0,
0xff1bc000)
14442/2@2:	 1.1962	            <- libc:realfree() = 0x2db915c8
14442/2@2:	 1.1965	          <- libc:cleanfree() = 0
14442/2@2:	 1.1969	          -> libc:t_delete(0x2db915c0, 0x800, 0x246bdaa8,
0xff1bc000)
14442/2@2:	 1.1972	            -> libc:t_splay(0x2db915c0, 0x749b4, 0x0, 0x0)
14442/2@2:	 1.1975	            <- libc:t_splay() = 0x506746e0
14442/2@2:	 1.1977	          <- libc:t_delete() = 0x2db915c0
14442/2@2:	 1.1980	        <- libc:_malloc_unlocked() = 0x2db915c8
14442/2@2:	 1.1982	        -> libthread:mutex_unlock(0xff1c05a0, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.1986	        <- libthread:mutex_unlock() = 0
14442/2@2:	 1.1990	      <- libc:malloc() = 0x2db915c8
14442/2@2:	 1.1993	      -> libc_psr:memset(0x2db915c8, 0x0, 0x800, 0x0)
14442/2@2:	 1.1997	      <- libc_psr:memset() = 0x2db915c8
14442/2@2:	 1.2000	      -> libc_psr:memcpy(0x2db915c8, 0x5409f090, 0x400,
0xfffffff8)
14442/2@2:	 1.2002	      <- libc_psr:memcpy() = 0x2db915c8
14442/2@2:	 1.2005	      -> libc:free(0x5409f090, 0x5409f490, 0x0, 0xfffffff8)
14442/2@2:	 1.2008	        -> libthread:mutex_lock(0xff1c05a0, 0x745f0, 0x0,
0xff1bc000)
14442/2@2:	 1.2011	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.2015	        -> libc:_free_unlocked(0x5409f090, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.2019	        <- libc:_free_unlocked() = 0x5409f090
14442/2@2:	 1.2024	      -> libthread:mutex_unlock(0xff1c05a0, 0x5409f490, 0x0,
0xfffffff8)
14442/2@2:	 1.2029	      <- libc:free() = 0
14442/2@2:	 1.2031	    <- libc:realloc_fds() = 0x2db919c8
14442/2@2:	 1.2034	    -> libc:realloc_fds(0xd2ffd184, 0xd2ffd180, 0xd2ffcf80,
0xfffffff8)
14442/2@2:	 1.2038	      -> libc:malloc(0x1000, 0x0, 0x0, 0x0)
14442/2@2:	 1.2042	        -> libthread:mutex_lock(0xff1c05a0, 0x754a8, 0x0,
0xff1bc000)
14442/2@2:	 1.2046	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.2049	        -> libc:_malloc_unlocked(0x1000, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.2053	          -> libc:cleanfree(0x0, 0x1, 0xff1c283c, 0x400)
14442/2@2:	 1.2056	            -> libc:realfree(0x5409f090, 0x744f8, 0x0,
0xff1bc000)
14442/2@2:	 1.2059	              -> libc:t_delete(0x5409f490, 0x13cc40, 0x400,
0x4216a350)
14442/2@2:	 1.2062	                -> libc:t_splay(0x5409f490, 0x749b4, 0x0,
0x0)
14442/2@2:	 1.2066	                <- libc:t_splay() = 0
14442/2@2:	 1.2068	              <- libc:t_delete() = 0x5409f490
14442/2@2:	 1.2071	            <- libc:realfree() = 0x5409f090
14442/2@2:	 1.2074	          <- libc:cleanfree() = 0
14442/2@2:	 1.2077	          -> libc:t_delete(0x5409f088, 0x13d048, 0x246bdaa8,
0x400)
14442/2@2:	 1.2079	            -> libc:t_splay(0x5409f088, 0x749b4, 0x0, 0x0)
14442/2@2:	 1.2082	            <- libc:t_splay() = 0
14442/2@2:	 1.2085	          <- libc:t_delete() = 0x5409f088
14442/2@2:	 1.2087	          -> libc:realfree(0x540a0098, 0x13c041, 0x13d048,
0x400)
14442/2@2:	 1.2091	          <- libc:realfree() = 0x540a0098
14442/2@2:	 1.2094	        <- libc:_malloc_unlocked() = 0x5409f090
14442/2@2:	 1.2097	        -> libthread:mutex_unlock(0xff1c05a0, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.2101	        <- libthread:mutex_unlock() = 0
14442/2@2:	 1.2104	      <- libc:malloc() = 0x5409f090
14442/2@2:	 1.2108	      -> libc_psr:memset(0x5409f090, 0x0, 0x1000, 0x0)
14442/2@2:	 1.2111	      <- libc_psr:memset() = 0x5409f090
14442/2@2:	 1.2114	      -> libc_psr:memcpy(0x5409f090, 0x2db915c8, 0x800,
0xfffffff8)
14442/2@2:	 1.2117	      <- libc_psr:memcpy() = 0x5409f090
14442/2@2:	 1.2120	      -> libc:free(0x2db915c8, 0x2db91dc8, 0x0, 0xfffffff8)
14442/2@2:	 1.2124	        -> libthread:mutex_lock(0xff1c05a0, 0x745f0, 0x0,
0xff1bc000)
14442/2@2:	 1.2127	        <- libthread:mutex_lock() = 0
14442/2@2:	 1.2131	        -> libc:_free_unlocked(0x2db915c8, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.2134	        <- libc:_free_unlocked() = 0x2db915c8
14442/2@2:	 1.2137	      -> libthread:mutex_unlock(0xff1c05a0, 0x2db91dc8, 0x0,
0xfffffff8)
14442/2@2:	 1.2141	      <- libc:free() = 0
14442/2@2:	 1.2144	    <- libc:realloc_fds() = 0x5409f890
14442/2@2:	 1.2147	    -> libc:_poll(0x5409f090, 0x102, 0xffffffff, 0xfffffff8)
14442/2:	 1.2161	poll(0x5409F090, 258, -1)			= 220
14442/2:		fd=4  ev=POLLRDNORM rev=0
14442/2:		fd=6  ev=POLLRDNORM rev=0
14442/2:		fd=7  ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=8  ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=10 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=13 ev=POLLRDNORM rev=0
14442/2:		fd=15 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=17 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=18 ev=POLLRDNORM rev=0
14442/2:		fd=19 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=20 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=21 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=22 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=23 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=24 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=25 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=26 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=27 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=28 ev=POLLRDNORM rev=POLLNVAL
14442/2:		fd=29 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=30 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=31 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=33 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=34 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=35 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=36 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=37 ev=POLLRDNORM rev=0
14442/2:		fd=38 ev=POLLRDNORM rev=0
14442/2:		fd=40 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=41 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		fd=42 ev=POLLRDNORM rev=0
14442/2:		fd=43 ev=POLLRDNORM rev=POLLRDNORM
14442/2:		...skipping 226 file descriptors...
14442/2@2:	 1.2169	    <- libc:_poll() = 220
14442/2@2:	 1.2177	    -> libc:___errno(0x20, 0x5409f090, 0xef, 0x5409f128)
14442/2@2:	 1.2184	      -> libthread:thr_main(0x0, 0x2433c, 0x0, 0x0)
14442/2@2:	 1.2187	      <- libthread:thr_main() = 0
14442/2@2:	 1.2192	    -> libc:thr_errnop(0x4e4650, 0x5409f090, 0xef,
0x5409f128)
14442/2@2:	 1.2197	    -> libthread:_thr_errnop(0xff0da574, 0x5409f090, 0x218bc,
0xff152a58)
14442/2@2:	 1.2201	    <- libc:___errno() = 0xff0c0270
14442/2@2:	 1.2206	    -> libc:free(0x5409f090, 0x5409f090, 0x218bc,
0xff152a58)
14442/2@2:	 1.2209	      -> libthread:mutex_lock(0xff1c05a0, 0x745f0, 0x0,
0xff1bc000)
14442/2@2:	 1.2212	      <- libthread:mutex_lock() = 0
14442/2@2:	 1.2215	      -> libc:_free_unlocked(0x5409f090, 0x0, 0x0,
0xff1bc000)
14442/2@2:	 1.2218	      <- libc:_free_unlocked() = 0x5409f090
14442/2@2:	 1.2221	    -> libthread:mutex_unlock(0xff1c05a0, 0x5409f090,
0x218bc, 0xff152a58)
14442/2@2:	 1.2224	    <- libc:free() = 0
14442/2@2:	 1.2227	  <- libc:select_large_fdset() = -1
14442/2@2:	 1.2230	  -> libc:___errno(0xffffffff, 0x660, 0xd2fff774, 0x0)
14442/2@2:	 1.2233	    -> libthread:thr_main(0x0, 0x2433c, 0x0, 0x0)
14442/2@2:	 1.2236	    <- libthread:thr_main() = 0
14442/2@2:	 1.2239	  -> libc:thr_errnop(0x4e4650, 0x660, 0xd2fff774, 0x0)
14442/2@2:	 1.2242	  -> libthread:_thr_errnop(0xff0da574, 0x660, 0x218bc,
0x62d4c)
14442/2@2:	 1.2245	  <- libc:___errno() = 0xff0c0270
14442/2@2:	 1.2248	  -> libc:time(0x0, 0x660, 0x218bc, 0x62d4c)
14442/2:	 1.2251	time() = 1100519933