From owner-freebsd-questions@freebsd.org Fri Oct 6 14:17:50 2017 Return-Path: Delivered-To: freebsd-questions@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 4CEA2E385CB for ; Fri, 6 Oct 2017 14:17:50 +0000 (UTC) (envelope-from ws@au.dyndns.ws) Received: from ipmail07.adl2.internode.on.net (ipmail07.adl2.internode.on.net [150.101.137.131]) by mx1.freebsd.org (Postfix) with ESMTP id 9335F1611 for ; Fri, 6 Oct 2017 14:17:49 +0000 (UTC) (envelope-from ws@au.dyndns.ws) Received: from ppp103-111.static.internode.on.net (HELO lillith-iv.ovirt.dyndns.ws) ([150.101.103.111]) by ipmail07.adl2.internode.on.net with ESMTP; 07 Oct 2017 00:42:02 +1030 X-Envelope-From: ws@au.dyndns.ws X-Envelope-To: freebsd-questions@freebsd.org Received: from predator-ii.buffyverse (predator-ii.buffyverse [172.17.17.136]) by lillith-iv.ovirt.dyndns.ws (8.14.9/8.14.9) with ESMTP id v96EBolq065852; Sat, 7 Oct 2017 00:41:52 +1030 (ACDT) (envelope-from ws@au.dyndns.ws) Message-ID: <1507299110.2905.8.camel@au.dyndns.ws> Subject: Re: Application startup time From: Wayne Sierke To: Janos Dohanics , FreeBSD Questions Date: Sat, 07 Oct 2017 00:41:50 +1030 In-Reply-To: <20171006083750.2c5331ac8c120ab9624115d4@3dresearch.com> References: <20171005133321.dc9114dee1a31346b96a4d08@3dresearch.com> <1507290916.2905.5.camel@au.dyndns.ws> <20171006083750.2c5331ac8c120ab9624115d4@3dresearch.com> Content-Type: text/plain; charset="UTF-8" X-Mailer: Evolution 3.24.2 FreeBSD GNOME Team Mime-Version: 1.0 Content-Transfer-Encoding: 7bit X-Greylist: inspected by milter-greylist-4.6.2 (lillith-iv.ovirt.dyndns.ws [172.17.17.142]); Sat, 07 Oct 2017 00:41:52 +1030 (ACDT) for IP:'172.17.17.136' DOMAIN:'predator-ii.buffyverse' HELO:'predator-ii.buffyverse' FROM:'ws@au.dyndns.ws' RCPT:'' X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.6.2 (lillith-iv.ovirt.dyndns.ws [172.17.17.142]); Sat, 07 Oct 2017 00:41:52 +1030 (ACDT) X-Scanned-By: MIMEDefang 2.78 on 172.17.17.142 X-Scanned-By: SpamAssassin 3.004001(2015-04-28) X-Scanned-By: ClamAV X-Spam-Score: -1 () ALL_TRUSTED X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 06 Oct 2017 14:17:50 -0000 On Fri, 2017-10-06 at 08:37 -0400, Janos Dohanics wrote: > On Fri, 06 Oct 2017 22:25:16 +1030 > Wayne Sierke wrote: > > > On Thu, 2017-10-05 at 13:33 -0400, Janos Dohanics wrote: > > > Greetings, > > > > > > I have a fairly recently built computer: i7-4790K CPU @ 4.00GHz, > > > 32GB RAM, GeForce GT 730, FreeBSD 10.4-BETA2. > > > > > > On this computer, I have thunderbird-52.3.0_3, installed from > > > ports. > > > > > > Thunderbird takes 38 seconds to start up, that is, from clicking > > > the > > > icon until Thunderbird offers a login prompt. > > > [...] > > > > Hi Janos, > > > > Best guess is that 38s includes 30s of "network issue" (probably > > dns) > > delay time. Given that the Windows TB client doesn't appear to > > suffer > > from the same problem - and assuming that it is configured to > > access > > the same mail servers - that may help you isolate a network > > configuration problem. A good place to start would be to compare > > the > > DNS configuration in FreeBSD vs the Windows VM. > > > > The "freezes" are a bit curious. If they're repeatable (i.e. occur > > in > > response to a specific action) you could put TB into "offline" mode > > and see if the freezes still occur. If they don't then they are > > probably related to the same network issue. > > Hi Wayne, > > DNS doesn't seem to be the bottleneck: > > $ time drill imap.telissant.net > ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 49359 > ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0 > ;; QUESTION SECTION: > ;; imap.telissant.net. IN A > > ;; ANSWER SECTION: > imap.telissant.net. 23887 IN A 104.225.1.170 > > ;; AUTHORITY SECTION: > > ;; ADDITIONAL SECTION: > > ;; Query time: 0 msec > ;; SERVER: 10.61.70.7 > ;; WHEN: Fri Oct 6 08:26:38 2017 > ;; MSG SIZE rcvd: 52 > > real 0m0.029s > user 0m0.001s > sys 0m0.001s > > 10.61.70.7 is the FreeBSD computer with the troublesome Thunderbird and > also is the host for the Win7 virtual machine, which looks up > 10.61.70.7 for DNS resolution. > > However, I ran truss(1) which showed errors like: > > 0.054980624 recvmsg(0x4,0x7fffffffdd40,0x0) ERR#35 'Resource temporarily unavailable' > 0.055094665 recvmsg(0x4,0x7fffffffddd0,0x0) ERR#35 'Resource temporarily unavailable' > 0.055193841 recvmsg(0x4,0x7fffffffdcc0,0x0) ERR#35 'Resource temporarily unavailable' > 0.055211203 recvmsg(0x4,0x7fffffffdcc0,0x0) ERR#35 'Resource temporarily unavailable' > 0.055297486 recvmsg(0x4,0x7fffffffdd60,0x0) ERR#35 'Resource temporarily unavailable' > 0.055314573 recvmsg(0x4,0x7fffffffdd60,0x0) ERR#35 'Resource temporarily unavailable' > 0.055435337 recvmsg(0x4,0x7fffffffddf0,0x0) ERR#35 'Resource temporarily unavailable' > 0.055452586 recvmsg(0x4,0x7fffffffddf0,0x0) ERR#35 'Resource temporarily unavailable' > > and many like these: > > 0.657764282 _umtx_op(0x8013151a0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x18,0x7fffddfccce8) ERR#60 'Operation timed out' > 0.672757944 _umtx_op(0x8013152f0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x18,0x7fffdc3bec98) ERR#60 'Operation timed out' > 0.688696796 _umtx_op(0x8013152f0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x18,0x7fffdc3bec98) ERR#60 'Operation timed out' > 0.706338501 _umtx_op(0x8013152f0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x18,0x7fffdc3bec98) ERR#60 'Operation timed out' > > and > > 1.905534690 getpeername(40,0x7fffdfdfc778,0x7fffdfdfc744) ERR#57 'Socket is not connected' > 1.967428986 getpeername(51,0x7fffdfdfc7a8,0x7fffdfdfc774) ERR#57 'Socket is not connected' > 1.967580715 getpeername(51,0x7fffdfdfc970,0x7fffdfdfc934) ERR#57 'Socket is not connected' > 1.997209982 getpeername(51,0x7fffdfdfc970,0x7fffdfdfc934) ERR#57 'Socket is not connected' > > and > > 6.783927993 _umtx_op(0x8013153e0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call' > 6.784120019 sigreturn(0x7fffdafb3500) ERR#4 'Interrupted system call' > 103.644696383 _umtx_op(0x8013153e0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call' > 103.644887820 sigreturn(0x7fffdafb3f40) ERR#4 'Interrupted system call' > 108.663319712 _umtx_op(0x8013153e0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call' > 108.663460460 sigreturn(0x7fffdafb3f40) ERR#4 'Interrupted system call' > 113.668752752 _umtx_op(0x8013153e0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call' > > Perhaps a bug in Thunderbird? While hardly a thorough comparison I can tell you that I get what appears to be a strikingly similar set of messages from truss with my Thunderbird. Un(?)fortunately I would say those messages are probably not significant. Below are some events whose timing in particular might make for an interesting comparison. First dns server connection: 0.194129868 open("/etc/resolv.conf",O_CLOEXEC,0666) = 13 (0xd) 0.194383797 open("/etc/nsswitch.conf",O_CLOEXEC,0666) = 13 (0xd) 0.196764530 open("/etc/hosts",O_CLOEXEC,0666) = 13 (0xd) 0.197027552 connect(14,{ AF_INET 172.17.17.42:53 },16) = 0 (0x0) 0.197582820 recvfrom(14,"\f\M-:\M^E\M^@\0\^A\0\^A\0\^A\0"...,65536,0x0,{ AF_INET 172.17.17.42:53 },0x7fffffffb8dc) = 93 (0x5d) 0.320484741 connect(16,{ AF_INET 172.17.17.42:53 },16) = 0 (0x0) 0.321022309 recvfrom(16,"|\^]\M^E\M^@\0\^A\0\^A\0\^A\0\^A"...,65536,0x0,{ AF_INET 172.17.17.42:53 },0x7fffffffb86c) = 93 (0x5d) First imap server connection and send/recv: 3.613094209 connect(46,{ AF_INET 172.17.17.142:993 },16) ERR#36 'Operation now in progress' 3.613132454 getpeername(46,0x7fffdf9fa970,0x7fffdf9fa934) ERR#57 'Socket is not connected' 3.614344524 sendto(46,"\^V\^C\^A\0\M^Q\^A\0\0\M^M\^C\^C"...,150,0x0,NULL,0x0) = 150 (0x96) 3.614382113 recvfrom(46,0x825157a80,5,0x0,0x0,0x0) ERR#35 'Resource temporarily unavailable' 3.687505051 recvfrom(46,"\^V\^C\^A\0005",5,0x0,NULL,0x0) = 5 (0x5)