Expansion of unit tests for utils/utils.go #818
Conversation
This commit expands the test coverage for the utils/utils.go module. The utils module uses the 'github.com/spf13/jwalterweatherman' (aka jww) package for logging. The tests take the approach of examining the log file that is produced by this module to verify correct behaviour. This avoids refactoring the utils module. The log file messages written by the jww module are of the form: <log level>: yyyy/mm/dd <string|error message> The checkLogFile function checks each of these parts in turn except for the date string, which is currently ignored. The final part of the log file format can either be a single error message, or a series of strings followed by an error message. Both the error message and the series of strings can be empty strings. The log file is checked using a combination of the regex package, along with the bufio scanner type. Each test logs to its own temporary log file. This is achieved with standard test setup and teardown functions. One consequence of these tests is that StopOnErr has been refactored into call a new unexported function doStopOnErr which contains the bulk of the original logic. This allows the same testing approach to be used with StopOnErr as with CheckErr and cutUsageMessage, rather than look at the exit status code of the test itself. An unfortunate side effect of this is that the author of the tests must now know if a log file is expected or not. If doStopOnErr determines that an empty error message would be written to the log file then nothing is written. In the context of the tests this means that the log file created by the test would have no contents. Consequently there would be nothing for the test to examine. This situation is indicated by the boolean flag logFileExoected in the testData struct, and processed by the logFileIsExpectedAndValid function. Although not ideal this was deemed a reasonable compromise.
|
Could you do a push -f to trigger new builds? |
|
Sorry all, I merged this prematurely. Should have waited @owenwaller to Hi @owenwaller, still here? Could you please look into it? Thanks! |
Rationale: Test failing on Windows with errors like this:
utils_test.go:177: Error: Could not remove file "f".
Error: remove C:\Users\appveyor\AppData\Local\Temp\utils_test_747965610:
The process cannot access the file because it is being used by another
process.
This reverts commit 6b28e38.
Sorry for my premature merge of Pull Request #818.
|
Hi Guys, Sorry I've just seen this. I've been extremely busy with other things for the last month. So, I've had a quick look and fairly obviously I don't see this failure on Linux. So my first question is do either of you two have a Windows box we can try something on, as I don't? But... the file "f" is the temporary file that is passed to the jww logger instance so we can later parse it to check the results. It's created with: That's lines 163, 164 in The error is suggesting that the file is locked. As you can see from the ci log the file names are all unique - the jww package (helpfully in this case) spits out the filename, but the only process that should ever touch this file is the one that created it which is the test itself. But, even if every TestXxxx in the set was run in its own process, the file that is used for logging is local to each TestXxxx function. So again is should be ok as only one process is accessing the file. So I'm kinda stumped at this point. Can someone give me some details of this appveyor thing and what their set up might be? I can see that it's only the appveyor build that falls over with this. My one short in the dark would be this.... If you look at the filename, it's all rooted on the same path and that path doesn't look to be very unique - i.e .it doesn't appear to have anything like a build number or string that relates it uniquely to hugo. So assuming a large enough scale and a fast enough rate, I guess it's possible for another process/ci run in the appveyor environment to create a file with the same name at the same path. I admit that seeing this it does make my prefix of "utils_test_" look less than ideal. So that can certainly be improved. But as I said this is a shot in the dark at this point. Owen |
|
Folks in order to take a look at this, I've set-up an account on AppVeyor and am trying building the current master branch via AppVeyor. So my last commit is: a389268. Having not used AppVeyor before this seems the simplest test I could do, since the master branch should be golden... But it's not building - See:https://ci.appveyor.com/project/owenwaller/hugo/build/1.0.23 for my latest attempt. Also AppVoyer is using go 1.3 wndows/amd64 as you can see from the build output, though I am not sure this is any effect. But I'm using go 1.4.1 locally on Linux and I don't have a problem building this branch. So can anyone spot anything that I might have missed? @spf13 Steve can you send me a copy of you AppVeyor settings so I can be sure that I have the same settings as a the build node you are using? Or create an Appveyor.yml and share that. But at the minute until I get the current master branch to build I'm a bit stuck :(. My plan is then to rebase my original pull request on the latest master and see if I can reproduce the issue. (I see similar behaviour is I try to build my original utils-test-code that contained the original pull request. So this looks like a Windows/AppVeyor only thing at the minute) Any help at this stage would be much appreciated. Owen |
|
I'm looking into this now. I'll try to share with you what I have. Best, -- On February 19, 2015 at 8:22:14 AM, Owen Waller ([email protected]) wrote: Folks in order to take a look at this, I've set-up an account on AppVeyor and am trying building the current master branch via AppVeyor. So my last commit is: a389268. Having not used AppVeyor before this seems the simplest test I could do, since the master branch should be golden... But it's not building - See:https://ci.appveyor.com/project/owenwaller/hugo/build/1.0.23 for my latest attempt. Also AppVoyer is using go 1.3 wndows/amd64 as you can see from the build output, though I am not sure this is any effect. But I'm using go 1.4.1 locally on Linux and I don't have a problem building this branch. So can anyone spot anything that I might have missed? @spf13 Steve can you send me a copy of you AppVeyor settings so I can be sure that I have the same settings as a the build node you are using? Or create an Appveyor.yml and share that. But at the minute until I get the current master branch to build I'm a bit stuck :(. My plan is then to rebase my original pull request on the latest master and see if I can reproduce the issue. (I see similar behaviour is I try to build my original utils-test-code that contained the original pull request. So this looks like a Windows/AppVeyor only thing at the minute) Any help at this stage would be much appreciated. Owen — |
|
Ok, @owenwaller here's the YAML file. It's quite short. |
|
There may still be problems if appveyor is still using 1.3 since some of the path issues are fixed by bug fixes that were part of 1.4. I'll try to take a look at this on Windows today. |
|
None of the path issues I fixed was fixed by 1.4 stuff. @owenwaller if you just push to your utils-test-cod branch, it will trigger a build with Hugo's build setup. |
|
Joel, Assuming this is the case - and I half suspect you may be correct - then A) ask Appveyor to see if they will officially add support for go 1.4.X Owen On Thu, 2015-02-19 at 08:34 -0800, Joel Scoble wrote:
Dr. Owen Waller +44 (0)757 882 9933 Company Number: NI604010 |
|
@spf13 - ta for the yml file. I've attached the YML file I'm using - the OK I've just tried it again and no dice. Results here: Now we are missing packages... and at least "github.com/kr/pty" should @bep - ok pushing to my repo public auto triggered the build on my Owen On Thu, 2015-02-19 at 09:51 -0800, Bjørn Erik Pedersen wrote:
Dr. Owen Waller +44 (0)757 882 9933 Company Number: NI604010 |
|
The build above fails for an old reason that is fixed: @owenwaller - as I asked you a couple time already, could you just trigger a new build by doing a push -f? |
|
@bep thanks for the info. I had been thinking about #699, problems with FindCWD() on Windows. and things affected by Go issue 8090 @owenwaller I guess, for now, using the suggested method is the way that we need to do testing if 1.4 is actually needed for test passing. @bep's comment make me wonder if my assumption that it was is true. |
|
@mohae @owenwaller the failure in the current failure above was caused by #878 - there may be other issues, but do a push first. |
|
@bep. Has a fix for #878 been merged into the hugo master line as of about So, I'm happy to do a push -f(*) but to the upstream repo (spf13/hugo?) I'm am quite happy to add a dummy commit onto the spf13/hugo.master (*)Not that the -f switch should be necessary. My push should not be Owen On Thu, 2015-02-19 at 10:18 -0800, Bjørn Erik Pedersen wrote:
Dr. Owen Waller +44 (0)757 882 9933 Company Number: NI604010 |
|
@owenwaller do a rebase against master, then push -f |
|
That won't make any difference in this case. My Alternatively, if you just take a branch the upstream master branch, and set up an appveyor account, you should see what I an currently seeing. In fact it would help if you can conform that assumption :) @spf13 |
|
@owenwaller git rebase master + git push -f. I'm asking you to do something that takes 20 keystrokes. Do it, or don't. |
|
@owenwaller we use a rebase approach, not merge. I believe it keeps things much cleaner and writes history in the order the commits are applied to the trunk, not in the order they are committed.
I'm sorry this issue has been such a prickly one. How can I help? I don't have access to a windows box at the moment (I'm traveling), but would be happy to help in another way.
|
|
I added a request for AppVeyor to upgrade to 1.4 on http://help.appveyor.com/discussions/problems/1215-go-14-support. They said they would update this week. But that won't address the failures within these tests on Windows. First I added a sleep to I then:
These changes, which were made incrementally, also failed due to the files still being in use. The root of the problem is that For Regardless, I don't think there is a way for these tests, as currently written, to pass until there are changes on the |
|
We can add ways to close things on jww. Do you want to send a PR? |
|
I've made some local changes to support closing things on jww, but I'm still getting inconsistent and strange results when running the tests on Windows. I'm trying to figure out the cause/if my assumption about the root cause of the failure is correct. |
|
@mohae Good man. I had a very quick glance at So I've been relying on the program exit behaviour on Linux to close the So I agree with you, the tests as written won't work. So I need to fix Now the question is where does the What does everyone else think? Also @mohae, I'm assuming you are running this on Windows? ;) If this Owen On Thu, 2015-02-19 at 13:32 -0800, Joel Scoble wrote:
Dr. Owen Waller +44 (0)757 882 9933 Company Number: NI604010 |
|
@owenwaller Windows does not allow open files to be deleted. I added a CloseLogFile() function that to jww that checks to see if the io.Writer is an *os.File and closes the file if it is. The LogHandle is set to ioutil.Discard prior to file.Close(). With this change, I was still getting "the process cannot access the file because it is being used by another process" error. This error persisted regardless of what hoops I had jww jump through. Also, some files would be removeable. Defering the Close seemed to affect the success rate, but numerours files were still being flagged as in use. I added a test to jww to test the new close function and the test was able to remove the closed LogFile. There is something going on with the code in utils_test.go that is contributing to this issue. I'm not sure what it is yet. |
|
@owenwaller I think you have some extraneous packages in your repo. Notice the "cannot find package..." errors. I don't think those are in hugo. Also, Hugo builds fine for me on Windows. |
|
Had a quick look at this (hate puzzles). @mohae - you can do But it will not fix this issue. My best guess is some Windows antivirus scanner issue. Maybe add this for now? |
|
@bep, good point about closing the file from the test. I overlooked the fact that LogHandle is exported. Disabling my antivirus did not affect the outcome. In addition, my test in jww properly removes the test log file after calling CloseLogFile() so I don't think that's the issue. Using runtime to separate out behavior for windows will work for now, but then either this functionality doesn't get tested for windows or the files remain in the temp directory. While I would prefer not to leave files in temp, it wouldn't be the first process to do so; even chrome does so. I will take another look at utils_test.go later today, when I have some additional time. I'm thinking that all of the function calls along with the various go routines that test creates still being in flight is contributing to this since creating simpler test situations work as expected. |
|
FWIW if you've not noticed yet, Appveyor has upgraded the installed go I have to say I'm impressed, The ticket suggested next week :) Owen On Thu, 2015-02-19 at 13:32 -0800, Joel Scoble wrote:
Dr. Owen Waller +44 (0)757 882 9933 Company Number: NI604010 |
|
Update: Well the good news is this is this is all now fixed, and everything is building on Appveyor now :). But there are a few subtle things you need to be aware of if you are also trying to set-up Appveyor to build your own forked hugo repository. Folks, Ok so something s still up with my Appveyor build or my repo is somehow So if you look here: This is after both a rebase of the upstream master onto my local master, Currently my last commit is @bep's Now, if I repeat what appveyor is doing locally on my Linux box I Note: Line one of this nukes my my entire src tree under So has anyone any idea just what is going on here and how to fix this? I am tempted to nuke my github repo and fork again, but I really don't If someone wants to take 10 minutes and clone my hugo repo to see what Thanks Owen On Thu, 2015-02-19 at 20:38 -0800, Joel Scoble wrote:
Dr. Owen Waller +44 (0)757 882 9933 Company Number: NI604010 |
|
@owenwaller the tests now pass on both Windows and Linux. The updated tests can be viewed at https://github.com/mohae/hugo/tree/utils_test. You can grab the updated code from my branch, or I can use that branch to submit a pull request. Please let me know if you want me to do so. The problem was related to the setup/teardown functions and the way the testing library works. Eliminating those functions and moving the file creation to the test functions that were using them, and closing those files there resolved the issue. To keep things cleaner, I created a tempDir on init() that both of the functions that create log files used. I also added a TestMain() function to run the tests from. After all of the tests are run, the tempDir is removed. Errors in TestMain and init() result in a panic. I'm not sure that error checking is needed on the removal of the temporary directory and its files, but since that was being checked in the original teardown function, and that error was the source of these test changes, I left it in. I also changed the name of the checkForExpectedStingOrFail() function to checkForExpectedStringOrFail() since I assumed that the Sting was erroneous. |
|
I forgot to mention that these changes did not require any changes to jww due to @bep's suggestion. |
|
@mohae thanks, well done. Give me a day - I'm away from my laptop for But you seem to be suggesting that this is some sort of interaction Owen On Fri, 2015-02-20 at 15:29 -0800, Joel Scoble wrote:
Dr. Owen Waller +44 (0)757 882 9933 Company Number: NI604010 |
|
@owenwaller: iirc, tests spawn go routines. The problems this code was exhibiting seemed to indicate that some go routines were still in flight while the teardown function was being executed, which is why some files could not be deleted. Moving around where the close occurred, e.g. defer vs not deferring, also affected how many files had this error. Also, runs could exhibit very minor variations. I had thought that sleeping some before the close and removal of the test file might allow whatever process that had a handle on the file to finish and the close/removal to succeed. That was not the case. Since I had already spent too much time trying to work out the issue, changing the way the tests were structured seemed more productive than doing further investigations to determine why those routines were still in flight and how to avoid that situation with the existing test code base. For tests, in general, keep the code the test is running as local to that test as possible, keep things as simple as possible to achieve your testing goals, and minimize the use of helper functions within the tests. Helper functions do have their place, and I do use them, mainly to help evaluation of results, but they should be used when necessary and not necessarily when convenient. You will notice that the functions that did remain in the updated tests were the ones that evaluated the results. The same is true with testing libraries. I went from using GoConvey, because of all of its "conveniences" baked in, to really disliking it. Then started using stretchr/testify, but now I mainly just use the standard testing package. The above is my opinion. It may or may not be useful. As you do more testing in Go, you will probably form your own opinions. Also, I noticed in you tended towards very verbose function names, Go tends to lean towards less verbose naming. I hope some of the above helps. |
Rationale: Test failing on Windows with errors like this:
utils_test.go:177: Error: Could not remove file "f".
Error: remove C:\Users\appveyor\AppData\Local\Temp\utils_test_747965610:
The process cannot access the file because it is being used by another
process.
This reverts commit 6b28e38.
Sorry for my premature merge of Pull Request gohugoio#818.
|
This pull request has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs. |
This commit expands the test coverage for the utils/utils.go module.
The utils module uses the 'github.com/spf13/jwalterweatherman' (aka jww)
package for logging. The tests take the approach of examining the log
file that is produced by this module to verify correct behaviour. This
avoids refactoring the utils module.
The log file messages written by the jww module are of the form:
: yyyy/mm/dd <string|error message>
The checkLogFile function checks each of these parts in turn except for
the date string, which is currently ignored. The final part of the log
file format can either be a single error message, or a series of
strings followed by an error message. Both the error message and the
series of strings can be empty strings.
The log file is checked using a combination of the regex package,
along with the bufio scanner type. Each test logs to its own temporary
log file. This is achieved with standard test setup and teardown
functions.
One consequence of these tests is that StopOnErr has been refactored
into call a new unexported function doStopOnErr which contains the bulk
of the original logic. This allows the same testing approach to be used
with StopOnErr as with CheckErr and cutUsageMessage, rather than look at
the exit status code of the test itself.
An unfortunate side effect of this is that the author of the tests must
now know if a log file is expected or not. If doStopOnErr determines
that an empty error message would be written to the log file then
nothing is written. In the context of the tests this means that the log
file created by the test would have no contents. Consequently there
would be nothing for the test to examine. This situation is indicated by
the boolean flag logFileExoected in the testData struct, and processed
by the logFileIsExpectedAndValid function.
Although not ideal this was deemed a reasonable compromise.