On Mon, 2021-03-29 at 16:50 +0900, Michael Paquier wrote: > On Fri, Mar 26, 2021 at 10:41:03PM +0000, Jacob Champion wrote: > > For a few of the bugs I was tracking down, it was imperative. The tests > > aren't isolated enough (or at all) to keep one from affecting the > > others. > > If the output of the log file is redirected to stderr and truncated, > while the connection attempts are isolated according to the position > where the file is truncated, I am not quite sure to follow this line > of thoughts. What actually happened? Should we make the tests more > stable instead?
It's not a matter of the tests being stable, but of the tests needing to change and evolve as the implementation changes. A big part of that is visibility into what the tests are doing, so that you can debug them. I'm sorry I don't have any explicit examples; the NSS work is pretty broad. > The kerberos have been running for one week now with > 11e1577a on HEAD, and look stable so it would be good to be consistent > on all fronts. I agree that it would be good in general, as long as the consistency isn't at the expense of usefulness. Keep in mind that the rotate-restart-slurp method comes from an existing test. I assume Andrew chose that method for the same reasons I did -- it works with what we currently have. > Hmm, okay. However, I still see a noticeable difference in the tests > without the additional restarts done so I would rather avoid this > cost. For example, on my laptop, the restarts make > authentication/t/001_password.pl last 7s. Truncating the logs without > any restarts bring the test down to 5.3s so that's 20% faster without > impacting its coverage. I agree that it'd be ideal not to have to restart the server. But 20% of less than ten seconds is less than two seconds, and the test suite has to run thousands of times to make up a single hour of debugging time that would be (hypothetically) lost by missing log files. (These are not easy tests for me to debug and maintain, personally -- maybe others have a different experience.) > If you want to keep this information around > for debugging, I guess that we could just print the contents of the > backend logs to regress_log_001_password instead? This could be done > with a simple wrapper routine that prints the past contents of the log > file before truncating them. I am not sure that we need to stop the > server while checking for the logs contents either, to start it again > a bit later in the test while the configuration does not change. that > costs in speed. Is the additional effort to create (and maintain) that new system worth two seconds per run? I feel like it's not -- but if you feel strongly then I can definitely look into it. Personally, I'd rather spend time making it easy for tests to get the log entries associated with a given connection or query. It seems like every suite has had to cobble together its own method of checking the log files, with varying levels of success/correctness. Maybe something with session_preload_libraries and the emit_log_hook? But that would be a job for a different changeset. > Causes each attempted connection to the server to be logged, > - as well as successful completion of client authentication. > + as well as successful completion of client authentication and > authorization. > I am wondering if this paragraph can be confusing for the end-user > without more explanation and a link to the "User Name Maps" section, > and if we actually need this addition at all. The difference is that > the authenticated log is logged before the authorized log, with user > name map checks in-between for some of the auth methods. HEAD refers > to the existing authorized log as "authentication" in the logs, while > you correct that. Which parts would you consider confusing/in need of change? I'm happy to expand where needed. Would an inline sample be more helpful than a textual explanation? Thanks again for all the feedback! --Jacob