From: Tom Lane <tgl@sss.pgh.pa.us>
To: Stephen Frost <sfrost@snowman.net>
cc: Peter Eisentraut <peter.eisentraut@2ndquadrant.com>,
        Alvaro Herrera <alvherre@2ndquadrant.com>,
        David Steele <david@pgmasters.net>, Joe Conway <mail@joeconway.com>,
        Magnus Hagander <magnus@hagander.net>,
        Michael Paquier <michael@paquier.xyz>,
        Nico Williams <nico@cryptonector.com>,
        PostgreSQL-development <pgsql-hackers@postgresql.org>,
        Robbie Harwood <rharwood@redhat.com>
Subject: Re: [PATCH v20] GSSAPI encryption support
In-reply-to: <20190404162452.GM6197@tamriel.snowman.net>
References: <7b7035e0-3691-ca63-0957-25d17dc11514@2ndquadrant.com>
 <CAOuzzgrztzi+g5vfd-dtNxx+MByZcy9nMVzavYZTgvZGHx98Hg@mail.gmail.com>
 <5406.1554388830@sss.pgh.pa.us> <20190404144818.GI6197@tamriel.snowman.net>
 <5945.1554389568@sss.pgh.pa.us> <20190404150054.GJ6197@tamriel.snowman.net>
 <7566.1554391003@sss.pgh.pa.us> <20190404152439.GK6197@tamriel.snowman.net>
 <8476.1554391968@sss.pgh.pa.us> <15827.1554394584@sss.pgh.pa.us>
 <20190404162452.GM6197@tamriel.snowman.net>
Comments: In-reply-to Stephen Frost <sfrost@snowman.net>
	message dated "Thu, 04 Apr 2019 12:24:52 -0400"
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-ID: <18055.1554397529.1@sss.pgh.pa.us>
Date: Thu, 04 Apr 2019 13:05:29 -0400
Message-ID: <18056.1554397529@sss.pgh.pa.us>
Precedence: bulk

Stephen Frost <sfrost@snowman.net> writes:
> * Tom Lane (tgl@sss.pgh.pa.us) wrote:
>> Watching the test logs, I see that essentially all the time on the RHEL6
>> machine is consumed by the two
>> # Running: /usr/sbin/kdb5_util create -s -P secret0
>> steps.  Is there a case for merging the two scripts so we only have to
>> do that once?  Maybe not, if nobody else sees this.

> I do think that mergeing them would be a good idea and I can look into
> that, though at least locally that step takes less than a second..  I
> wonder if you might strace (or whatever is appropriate) that kdb5_util
> and see what's taking so long.  I seriously doubt it's the actual
> kdb5_util code and strongly suspect it's some kernel call.

"strace -r" pins the blame pretty firmly on /dev/random:

     0.000076 open("/dev/random", O_RDONLY) = 3
     0.000227 fcntl(3, F_SETFD, FD_CLOEXEC) = 0
     0.000061 fstat(3, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 8), ...}) = 0
     0.000068 read(3, "\336&\301\310V\344q\217\264-\262\320w-", 64) = 14
     0.000091 read(3, "\326\353I\371$\361", 50) = 6
    15.328306 read(3, "\214\301\313]I\325", 44) = 6
    17.418929 read(3, "z\251\37\275\365\24", 38) = 6
    13.366997 read(3, "6\257I\315f\3", 32) = 6
    11.457994 read(3, "\370\275\2765\31(", 26) = 6
    23.472194 read(3, "\226\r\314\373\2014", 20) = 6
    11.746848 read(3, "\335\336BR\30\322", 14) = 6
    20.823940 read(3, "\366\214\r\211\0267", 8) = 6
    14.429214 read(3, ",g", 2)          = 2
    15.494835 close(3)                  = 0

There's no other part of the trace that takes more than ~ 0.1s.
So this boils down to the old bugaboo about how much entropy
there really is in /dev/random.

			regards, tom lane