tests: Run functional test on Windows and enable it on Appveyor #14007

ken2812221 commented at 11:41 AM on August 20, 2018: contributor

This PR do the following things:

Make functional tests compatible with Windows
Print color output in functional tests for Windows 10
Run util and functional tests on appveyor
Do not run symlink tests on Windows

Note:

The wallet_multiwallet.py fail is unrelated to the test framework, it's a bug related to c++ code or maybe dependencies. bitcoind would exit with 0xC0000005(Access violation) during shutdown occasionally. Disable this for now.
Not using --failfast because this is still in experimental. We should track if there is any other error.
Disable ZMQ tests because the python zmq library could cause access violation sometimes.
Disable feature_notifications because Bitcoin Core handles the command in different thread, whicha can cause a race condition.

fanquake added the label Tests on Aug 20, 2018

ken2812221 force-pushed on Aug 20, 2018

ken2812221 force-pushed on Aug 21, 2018

MarcoFalke commented at 8:22 PM on August 22, 2018: member

I think there is some interference with a firewall or something that kills the bitcoind processes?

in appveyor.yml:65 in 2d30c7c50a outdated

  57 | +
  58 | +    copy c:\\tools\\vcpkg\\installed\\x64-windows\\bin\\libeay32.dll .
  59 | +
  60 | +    python -m pip install zmq 2>&1 | %{ "$_" }
  61 | +
  62 | +    python test\\functional\\test_runner.py --force --combinedlogslen=4000 --quiet

MarcoFalke commented at 8:23 PM on August 22, 2018:

Could as a first step only run the util tests?

ken2812221 commented at 2:36 AM on August 23, 2018:

You mean to drop away functional tests and replace it with util tests from this PR, and re-add the funfctional tests in another PR?

ken2812221 force-pushed on Aug 23, 2018

ken2812221 commented at 4:31 AM on August 23, 2018: contributor

It is really hard to see blue color on powershell, so change the color to green

DrahtBot commented at 4:46 AM on August 23, 2018: member

Note to reviewers: This pull request conflicts with the following ones:

#14275 (tests: Write the notification message to different files to avoid race condition in feature_notifications.py by ken2812221)
#14241 (appveyor: trivial build cache improvement by ken2812221)
#14237 (Fix for test runner UnicodeDecodeError when utf-8 is not supported by sanket1729)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

ken2812221 commented at 10:50 AM on August 23, 2018: contributor

I think there is some interference with a firewall or something that kills the bitcoind processes?

I agree with you, they are all passed on my Windows PC.

MarcoFalke commented at 1:37 PM on August 23, 2018: member

They didn't pass for me on Windows 7

ken2812221 force-pushed on Aug 23, 2018

ken2812221 commented at 1:01 AM on August 24, 2018: contributor

Oh, it's occasionally. I tested to run it 10 times, 8 times failed, 2 times succeed.

ken2812221 force-pushed on Aug 24, 2018

ken2812221 force-pushed on Aug 25, 2018

ken2812221 renamed this:
~~[WIP] appveyor: Run functional test on appveyor~~
appveyor: Run functional test on appveyor
on Aug 25, 2018

ken2812221 force-pushed on Aug 25, 2018

ken2812221 commented at 8:26 AM on August 25, 2018: contributor

This is ready for review, the wallet_multiwallet.py fail is unrelated to the test framework. It is a bug related to c++ code, it would exit with 0xC0000005(Acccess violation) during shutdown occasionally.

ken2812221 force-pushed on Aug 25, 2018

in test/util/bitcoin-util-test.py:80 in fe533cfcf4 outdated

  76 | @@ -77,7 +77,7 @@ def bctest(testDir, testObj, buildenv):
  77 |      are not as expected. Error is caught by bctester() and reported.
  78 |      """
  79 |      # Get the exec names and arguments
  80 | -    execprog = os.path.join(buildenv["BUILDDIR"], "src", testObj["exec"] + buildenv["EXEEXT"])
  81 | +    execprog = os.path.join(os.environ.get('BITCOINEXEPATH', '') or os.path.join(buildenv["BUILDDIR"], "src"), testObj["exec"] + buildenv["EXEEXT"])

MarcoFalke commented at 1:52 PM on August 25, 2018:

Why is this change needed?

ken2812221 commented at 1:59 PM on August 25, 2018:

The binary built by MSVC is not at src/, so it needs a variable to indicate the binary location.

in appveyor.yml:14 in fe533cfcf4 outdated

   4 | @@ -5,16 +5,19 @@ configuration: Release
   5 |  platform: x64
   6 |  environment:
   7 |    APPVEYOR_SAVE_CACHE_ON_ERROR: true
   8 | -cache: C:\tools\vcpkg\installed\
   9 | +  PYTHONIOENCODING: utf-8
  10 | +cache:
  11 | +- C:\tools\vcpkg\installed
  12 | +- build_msvc\cache

MarcoFalke commented at 3:00 PM on August 25, 2018:

I think this caching fix can be submitted in an independent pr

ken2812221 commented at 3:20 PM on August 25, 2018:

fine

ken2812221 force-pushed on Aug 25, 2018

DrahtBot added the label Needs rebase on Aug 26, 2018

ken2812221 force-pushed on Aug 26, 2018

DrahtBot removed the label Needs rebase on Aug 26, 2018

ken2812221 renamed this:
~~appveyor: Run functional test on appveyor~~
tests: Run functional test on Windows
on Aug 27, 2018

ken2812221 force-pushed on Aug 27, 2018

ken2812221 commented at 2:31 PM on August 27, 2018: contributor

I think we could disable those problematic tests for now.

ken2812221 commented at 4:39 PM on August 27, 2018: contributor

I think there is some interference with a firewall or something that kills the bitcoind processes?

Solve this problem by using new connection every time we call RPC. Not sure why would that happen.

MarcoFalke commented at 5:13 PM on August 27, 2018: member

What happened to the cache fix? I think we are not yet properly caching the intermediate compile results?

ken2812221 commented at 7:42 PM on August 27, 2018: contributor

@MarcoFalke I add the build cache in #14086

ken2812221 force-pushed on Aug 29, 2018

ken2812221 commented at 10:57 AM on August 29, 2018: contributor

Update: Based on #14086, following #14092

ken2812221 force-pushed on Sep 3, 2018

ken2812221 force-pushed on Sep 4, 2018

ken2812221 force-pushed on Sep 5, 2018

ken2812221 commented at 9:50 AM on September 5, 2018: contributor

#14086 has been merged, this is ready for review.

ken2812221 renamed this:
~~tests: Run functional test on Windows~~
tests: Run functional test on Windows and enable it on Appveyor
on Sep 5, 2018

in test/functional/combine_logs.py:30 in d355f4e579 outdated

  24 | @@ -25,8 +25,8 @@ def main():
  25 |      parser.add_argument('--html', dest='html', action='store_true', help='outputs the combined log as html. Requires jinja2. pip install jinja2')
  26 |      args, unknown_args = parser.parse_known_args()
  27 |  
  28 | -    if args.color and os.name != 'posix':
  29 | -        print("Color output requires posix terminal colors.")
  30 | +    if args.color and os.name == 'nt' and sys.getwindowsversion().build < 14393:
  31 | +        print("Color output requires Windows 10 anniversary update or later.")
  32 |          sys.exit(1)

MarcoFalke commented at 12:58 PM on September 5, 2018:

I think this check can be removed. Color is off by default and if someone specifies color, they have a reason to do so (maybe write to a file that is read on a different os/platform)

in test/functional/test_framework/authproxy.py:83 in d355f4e579 outdated

  76 | @@ -76,6 +77,7 @@ def __init__(self, service_url, service_name=None, timeout=HTTP_TIMEOUT, connect
  77 |          passwd = None if self.__url.password is None else self.__url.password.encode('utf8')
  78 |          authpair = user + b':' + passwd
  79 |          self.__auth_header = b'Basic ' + base64.b64encode(authpair)
  80 | +        self.timeout = timeout
  81 |  
  82 |          if connection:
  83 |              # Callables re-use the connection of the original proxy

MarcoFalke commented at 1:03 PM on September 5, 2018:

I think this is no longer supported? So could remove the named arg "connection"?

in test/functional/test_framework/authproxy.py:112 in d355f4e579 outdated

 103 | @@ -102,6 +104,12 @@ def _request(self, method, path, postdata):
 104 |                     'User-Agent': USER_AGENT,
 105 |                     'Authorization': self.__auth_header,
 106 |                     'Content-type': 'application/json'}
 107 | +        if os.name == 'nt':
 108 | +            port = 80 if self.__url.port is None else self.__url.port
 109 | +            if self.__url.scheme == 'https':
 110 | +                self.__conn = http.client.HTTPSConnection(self.__url.hostname, port, timeout=self.timeout)
 111 | +            else:
 112 | +                self.__conn = http.client.HTTPConnection(self.__url.hostname, port, timeout=self.timeout)

MarcoFalke commented at 1:05 PM on September 5, 2018:

Could move this into a method def _set_conn(self): to avoid duplication?

in test/functional/test_framework/authproxy.py:99 in d355f4e579 outdated

 103 | @@ -102,6 +104,12 @@ def _request(self, method, path, postdata):
 104 |                     'User-Agent': USER_AGENT,
 105 |                     'Authorization': self.__auth_header,
 106 |                     'Content-type': 'application/json'}
 107 | +        if os.name == 'nt':

MarcoFalke commented at 1:05 PM on September 5, 2018:

Could add a comment that this works around some issues on windows.

in test/functional/test_framework/test_node.py:272 in d355f4e579 outdated

 268 | @@ -269,7 +269,7 @@ def assert_start_raises_init_error(self, extra_args=None, expected_msg=None, mat
 269 |                  # Check stderr for expected message
 270 |                  if expected_msg is not None:
 271 |                      log_stderr.seek(0)
 272 | -                    stderr = log_stderr.read().decode('utf-8').strip()
 273 | +                    stderr = log_stderr.read().decode('utf-8', 'ignore').strip()

MarcoFalke commented at 1:06 PM on September 5, 2018:

Hmm, any rationale for this? I'd prefer to throw if the log was not unicode.

ken2812221 commented at 1:25 PM on September 5, 2018:

an error message thrown by boost is always localized(translated) and use ANSI encoding, so it would always throw an error. I don't know any solution to fix this. There is no way to specify the error message format.

For now, I could revert this because appveyor is using English, but it would cause problem if the user is running a non-English Windows. It can be marked as an issue with #13869.

ken2812221 commented at 8:42 PM on September 11, 2018:

Done in #14192

in test/functional/test_runner.py:476 in d355f4e579 outdated

 472 | @@ -463,7 +473,7 @@ def get_next(self):
 473 |                      proc.send_signal(signal.SIGINT)
 474 |                  if proc.poll() is not None:
 475 |                      log_out.seek(0), log_err.seek(0)
 476 | -                    [stdout, stderr] = [log_file.read().decode('utf-8') for log_file in (log_out, log_err)]
 477 | +                    [stdout, stderr] = [log_file.read().decode('utf-8', 'ignore') for log_file in (log_out, log_err)]

MarcoFalke commented at 1:11 PM on September 5, 2018:

I'd prefer to keep the throw on non-unicode log files.

ken2812221 commented at 3:05 PM on September 5, 2018:

Same as above.

ken2812221 force-pushed on Sep 5, 2018

ken2812221 force-pushed on Sep 6, 2018

ken2812221 force-pushed on Sep 7, 2018

in appveyor.yml:48 in d96578fd2a outdated

  44 | @@ -39,7 +45,17 @@ build_script:
  45 |  after_build:
  46 |  - cmd: move build_msvc\%PLATFORM%\%CONFIGURATION%\*.iobj build_msvc\cache\
  47 |  - cmd: move build_msvc\%PLATFORM%\%CONFIGURATION%\*.ipdb build_msvc\cache\
  48 | -- cmd: del C:\Users\appveyor\clcache\stats.txt
  49 | +- cmd: clcache -z

ken2812221 commented at 2:22 PM on September 7, 2018:

I want to avoid re-uploading cache files if there is no change in #14086, I chose to delete the stats file entirely. But that was a mistake, it would also clear the cache size information which extremely increase cache size.

After then, I realize that clcache has a command to clear hit and miss info but retain size info: clcache -z

See: https://github.com/frerich/clcache/blob/master/README.asciidoc#options

ken2812221 commented at 10:52 PM on September 7, 2018: contributor

@NicolasDorier @sipsorcery Would you mind reviewing this?

ken2812221 force-pushed on Sep 8, 2018

sipsorcery commented at 7:50 PM on September 8, 2018: member

tACK https://github.com/bitcoin/bitcoin/pull/14007/commits/1223343106c4c889360aeb019d1bfe703708534f

in appveyor.yml:54 in 1223343106 outdated

  50 | +before_test:
  51 | +- ps:  $conf_ini = (Get-Content([IO.Path]::Combine($env:APPVEYOR_BUILD_FOLDER, "test", "config.ini.in")))
  52 | +- ps:  $conf_ini = $conf_ini.Replace("@abs_top_srcdir@", $env:APPVEYOR_BUILD_FOLDER).Replace("@abs_top_builddir@", $env:APPVEYOR_BUILD_FOLDER).Replace("@EXEEXT@", ".exe")
  53 | +- ps:  $conf_ini = $conf_ini.Replace("@ENABLE_WALLET_TRUE@", "").Replace("@BUILD_BITCOIN_UTILS_TRUE@", "").Replace("@BUILD_BITCOIND_TRUE@", "").Replace("@ENABLE_ZMQ_TRUE@", "")
  54 | +- ps:  $utf8 = New-Object System.Text.UTF8Encoding $false
  55 | +- ps:  '[IO.File]::WriteAllLines([IO.Path]::Combine($env:APPVEYOR_BUILD_FOLDER, "test", "config.ini"), $conf_ini, $utf8)'

NicolasDorier commented at 5:59 AM on September 9, 2018:

Why is it in ' ? This command just print the string, it does not save on config.ini

ken2812221 commented at 6:02 AM on September 9, 2018:

This is to escape that [ has special meaning in yaml. The actual command does not contain the quote.

in appveyor.yml:19 in 1223343106 outdated

  14 |  - build_msvc\cache
  15 |  init:
  16 |  - cmd: set PATH=C:\Python36-x64;C:\Python36-x64\Scripts;%PATH%
  17 | +- cmd: set BITCOINPATH=%APPVEYOR_BUILD_FOLDER%\build_msvc\%PLATFORM%\%CONFIGURATION%
  18 | +- cmd: set BITCOIND=%BITCOINPATH%\bitcoind.exe
  19 | +- cmd: set BITCOINCLI=%BITCOINPATH%\bitcoin-cli.exe

NicolasDorier commented at 6:03 AM on September 9, 2018:

Would be better to not mix and use powershell.

ken2812221 commented at 6:06 AM on September 9, 2018:

Any reason why that is better?

NicolasDorier commented at 6:05 AM on September 9, 2018: contributor

Why, when I build from visual studio directly, bitcoind.exe is not in bitcoindir\build_msvc\%PLATFORM%\%CONFIGURATION%\bitcoind.exe but in bitcoindir\build_msvc\%CONFIGURATION%\bitcoind.exe ?

ken2812221 commented at 6:19 AM on September 9, 2018: contributor

@NicolasDorier How about now? If you prefer this, I will squash it.

in appveyor.yml:17 in 319aa317c3 outdated

  12 |  - C:\tools\vcpkg\installed
  13 |  - C:\Users\appveyor\clcache
  14 |  - build_msvc\cache
  15 |  init:
  16 |  - cmd: set PATH=C:\Python36-x64;C:\Python36-x64\Scripts;%PATH%
  17 | +- ps:  $env:BITCOINPATH = $env:APPVEYOR_BUILD_FOLDER + "\build_msvc\x64\Release"

NicolasDorier commented at 6:21 AM on September 9, 2018:

$env:Platform$env:Configuration

NicolasDorier commented at 6:22 AM on September 9, 2018:

"$env:APPVEYOR_BUILD_FOLDER\build_msvc\$env:Platform\$env:Configuration"

ken2812221 force-pushed on Sep 9, 2018

NicolasDorier commented at 6:27 AM on September 9, 2018: contributor

Trying to debug this (strange error, as bitcoind is started correctly)

PS C:\Sources\bitcoin> python test\functional\test_runner.py --force wallet_multiwallet.py
Temporary test directory at C:\Users\NICOLA~1\AppData\Local\Temp/test_runner_20180909_152112
.........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
wallet_multiwallet.py failed, Duration: 295 s

stdout:
2018-09-09T06:21:13.160000Z TestFramework (INFO): Initializing test directory C:\Users\NICOLA~1\AppData\Local\Temp\test_runner_20180909_152112\wallet_multiwallet_0
2018-09-09T06:26:08.498000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 293, in start_nodes
    node.wait_for_rpc_connection()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 178, in wait_for_rpc_connection
    self._raise_assertion_error("Unable to connect to bitcoind")
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 106, in _raise_assertion_error
    raise AssertionError(self._node_msg(msg))
AssertionError: [node 0] Unable to connect to bitcoind

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 160, in main
    self.setup_network()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 233, in setup_network
    self.setup_nodes()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 248, in setup_nodes
    self.start_nodes()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 296, in start_nodes
    self.stop_nodes()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 312, in stop_nodes
    node.stop_node()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 194, in stop_node
    self.stop()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 123, in __getattr__
    assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
AssertionError: [node 0] Error: no RPC connection
2018-09-09T06:26:08.510000Z TestFramework (INFO): Stopping nodes
[node 1] Cleaning up leftover process
[node 0] Cleaning up leftover process


stderr:
Traceback (most recent call last):
  File "C:\Sources\bitcoin/test/functional/wallet_multiwallet.py", line 305, in <module>
    MultiWalletTest().main()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 186, in main
    self.stop_nodes()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 312, in stop_nodes
    node.stop_node()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 194, in stop_node
    self.stop()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 123, in __getattr__
    assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
AssertionError: [node 0] Error: no RPC connection



TEST                  | STATUS    | DURATION

wallet_multiwallet.py | ✖ Failed  | 295 s

ALL                   | ✖ Failed  | 295 s (accumulated)
Runtime: 295 s

in appveyor.yml:19 in b913075315 outdated

  13 | @@ -14,9 +14,9 @@ cache:
  14 |  - build_msvc\cache
  15 |  init:
  16 |  - cmd: set PATH=C:\Python36-x64;C:\Python36-x64\Scripts;%PATH%
  17 | -- cmd: set BITCOINPATH=%APPVEYOR_BUILD_FOLDER%\build_msvc\%PLATFORM%\%CONFIGURATION%
  18 | -- cmd: set BITCOIND=%BITCOINPATH%\bitcoind.exe
  19 | -- cmd: set BITCOINCLI=%BITCOINPATH%\bitcoin-cli.exe
  20 | +- ps:  $env:BITCOINPATH = $env:APPVEYOR_BUILD_FOLDER + "\build_msvc\" + $env:PLATFORM + "\" + $env:CONFIGURATION
  21 | +- ps:  $env:BITCOIND = $env:BITCOINPATH + "\bitcoind.exe"
  22 | +- ps:  $env:BITCOINCLI = $env:BITCOINPATH + "\bitcoin-cli.exe"

NicolasDorier commented at 6:28 AM on September 9, 2018:

You can keep like this is you feel lazy, but

$env:BITCOINPATH = "$env:APPVEYOR_BUILD_FOLDER\build_msvc\$env:PLATFORM\$env:CONFIGURATION" is more readable

ken2812221 commented at 6:31 AM on September 9, 2018:

done

ken2812221 force-pushed on Sep 9, 2018

ken2812221 commented at 6:38 AM on September 9, 2018: contributor

@NicolasDorier You get that error in every test or just wallet_multiwallet?

in appveyor.yml:59 in 944194c6df outdated

  56 |  test_script:
  57 |  - cmd: build_msvc\%PLATFORM%\%CONFIGURATION%\test_bitcoin.exe
  58 | +- cmd: build_msvc\%PLATFORM%\%CONFIGURATION%\bench_bitcoin.exe -evals=1 -scaling=0
  59 | +- cmd: python test\util\bitcoin-util-test.py
  60 | +- cmd: python test\util\rpcauth-test.py
  61 | +- cmd: python test\functional\test_runner.py --force --quiet --combinedlogslen=4000 --exclude "wallet_multiwallet,wallet_multiwallet.py --usecli"

NicolasDorier commented at 6:40 AM on September 9, 2018:

using ps here would be better.

ken2812221 commented at 6:45 AM on September 9, 2018:

ps on appveyor can't show unicode correctly https://help.appveyor.com/discussions/problems/1105-utf-8-characters-in-powershell-log

ken2812221 commented at 6:49 AM on September 9, 2018:

So you would prefer to use ps if possible? If so, I would change those except

python test\functional\test_runner.py --force --quiet --combinedlogslen=4000 --exclude "wallet_multiwallet,wallet_multiwallet.py --usecli"

because of appveyor ps issue.

NicolasDorier commented at 6:54 AM on September 9, 2018:

Interesting, yes I think that is a good choice. Should probably add a short comment about it.

unknown commented at 6:55 AM on September 9, 2018:

ps

NicolasDorier commented at 7:02 AM on September 9, 2018: contributor

Does not seem to be only this test, probably a problem on my end. Searching why.

ken2812221 commented at 7:06 AM on September 9, 2018: contributor

@NicolasDorier Did you switch to my PR branch? I usually see that issue on current master.

ken2812221 force-pushed on Sep 9, 2018

NicolasDorier commented at 7:12 AM on September 9, 2018: contributor

I need to go, will check/debug again later,

node1.debug.log node0.debug.log

after trying python test\functional\test_runner.py --force wallet_hd.py

ken2812221 force-pushed on Sep 9, 2018

NicolasDorier commented at 7:12 AM on September 9, 2018: contributor

yes I am on patch-2

ken2812221 force-pushed on Sep 9, 2018

in appveyor.yml:57 in 161e83a5f8 outdated

  55 | +- ps:  '[IO.File]::WriteAllLines([IO.Path]::Combine(${env:APPVEYOR_BUILD_FOLDER}, "test", "config.ini"), $conf_ini, ${utf8})'
  56 |  test_script:
  57 |  - cmd: build_msvc\%PLATFORM%\%CONFIGURATION%\test_bitcoin.exe
  58 | +- ps:  '& "build_msvc\${env:PLATFORM}\${env:CONFIGURATION}\bench_bitcoin.exe" -evals=1 -scaling=0'
  59 | +- ps:  python test\util\bitcoin-util-test.py
  60 | +- cmd: python test\util\rpcauth-test.py

ken2812221 commented at 7:25 AM on September 9, 2018:

@NicolasDorier Keep this cmd because appveyor ps hate stderr: https://ci.appveyor.com/project/DrahtBot/bitcoin/build/master.991

NicolasDorier commented at 12:07 PM on September 9, 2018: contributor

Ok so this is strange,

python test\functional\test_runner.py --force wallet_hd.py fails (actually any test fail on my machine)

2018-09-09 11:58:02.382258 Bitcoin Core version v1.15.99.0-unk (release build)
2018-09-09 11:58:02.382258 InitParameterInteraction: parameter interaction: -whitelistforcerelay=1 -> setting -whitelistrelay=1
2018-09-09 11:58:02.384259 Validating signatures for all blocks.
2018-09-09 11:58:02.384259 Setting nMinimumChainWork=0000000000000000000000000000000000000000000000000000000000000000
2018-09-09 11:58:02.384259 Using the 'standard' SHA256 implementation
2018-09-09 11:58:03.275254 RandAddSeedPerfmon: 918320 bytes
2018-09-09 11:58:03.286259 Default data directory C:\Users\NicolasDorier\AppData\Roaming\Bitcoin
2018-09-09 11:58:03.286259 Using data directory C:\Users\NICOLA~1\AppData\Local\Temp\test_runner_20180909_205801\wallet_hd_0\node0\regtest
2018-09-09 11:58:03.286259 Using config file C:\Users\NICOLA~1\AppData\Local\Temp\test_runner_20180909_205801\wallet_hd_0\node0\bitcoin.conf
2018-09-09 11:58:03.286259 Using at most 125 automatic connections (2048 file descriptors available)
2018-09-09 11:58:03.298258 Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2018-09-09 11:58:03.329257 Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2018-09-09 11:58:03.329257 Using 2 threads for script verification
2018-09-09 11:58:03.330258 scheduler thread start
2018-09-09 11:58:03.331259 Allowing HTTP connections from: 127.0.0.0/8 ::1/128 
2018-09-09 11:58:03.332258 Binding RPC on address ::1 port 18443
2018-09-09 11:58:03.332258 Binding RPC on address ::1 port 18443 failed.
2018-09-09 11:58:03.332258 Binding RPC on address 127.0.0.1 port 18443
2018-09-09 11:58:03.332258 Binding RPC on address 127.0.0.1 port 18443 failed.

Meanwhile my config file has 16000 set, but 18443 is resolved by bitcoind.

regtest=1
[regtest]
port=11000
rpcport=16000
server=1
keypool=1
discover=0
listenonion=0
printtoconsole=0
bind=127.0.0.1

ken2812221 commented at 12:16 PM on September 9, 2018: contributor

Weird, why is your temporary directory is C:\Users\NICOLA~1\AppData\Local\Temp\ when your username is NicolasDorier? Do C:\Users\NICOLA~1\ exist?

NicolasDorier commented at 12:21 PM on September 9, 2018: contributor

@ken2812221 yes it exists. I think it is an alternative name for C:\Users\NicolasDorier\. I don't know why bitcoin python test use the ~1 version. Do you want I check? I don't think that is the issue though.

ken2812221 commented at 2:10 PM on September 9, 2018: contributor

Why is your version is v1.15.99.0? if it is the same as 0.15.99, it may not able to read conf file properly, especially for rpcport setting.

sipsorcery commented at 8:08 PM on September 9, 2018: member

@NicolasDorier @ken2812221 The C:\Users\NICOLA~1\ is the Windows "Short" directory name, a hangover from MS-DOS naming I also doubt it's causing a problem.

The python tests work correctly for me on an AppVeyor build. They fail in a few different spots on my x64 Windows 10 machine with Python 3.7. I mucked around trying to get the first failing test working but I suspect the openssl interface has changed from what the bitcoin-core test scripts are expecting.

python test\functional\test_runner.py --force feature_block.py
Temporary test directory at C:\Users\aaron\AppData\Local\Temp/test_runner_20180909_220340

feature_block.py failed, Duration: 0 s

stdout:


stderr:
Traceback (most recent call last):
  File "C:\dev\github\sipsorcery_bitcoin_msvc/test/functional/feature_block.py", line 12, in <module>
    from test_framework.key import CECKey
  File "C:\dev\github\sipsorcery_bitcoin_msvc\test\functional\test_framework\key.py", line 14, in <module>
    ssl = ctypes.cdll.LoadLibrary(ctypes.util.find_library ('ssl') or 'libeay32')
  File "C:\Users\aaron\AppData\Local\Programs\Python\Python37\lib\ctypes\__init__.py", line 434, in LoadLibrary
    return self._dlltype(name)
  File "C:\Users\aaron\AppData\Local\Programs\Python\Python37\lib\ctypes\__init__.py", line 356, in __init__
    self._handle = _dlopen(self._name, mode)
OSError: [WinError 126] The specified module could not be found



TEST             | STATUS    | DURATION

feature_block.py | ✖ Failed  | 0 s

ALL              | ✖ Failed  | 0 s (accumulated)
Runtime: 0 s

PS C:\dev\github\sipsorcery_bitcoin_msvc> python test\functional\test_runner.py --force feature_block.py
Temporary test directory at C:\Users\aaron\AppData\Local\Temp/test_runner_20180909_220422

feature_block.py failed, Duration: 0 s

stdout:


stderr:
Traceback (most recent call last):
  File "C:\dev\github\sipsorcery_bitcoin_msvc/test/functional/feature_block.py", line 12, in <module>
    from test_framework.key import CECKey
  File "C:\dev\github\sipsorcery_bitcoin_msvc\test\functional\test_framework\key.py", line 14, in <module>
    ssl = ctypes.cdll.LoadLibrary(ctypes.util.find_library ('ssl') or 'libeay32')
  File "C:\Users\aaron\AppData\Local\Programs\Python\Python37\lib\ctypes\__init__.py", line 434, in LoadLibrary
    return self._dlltype(name)
  File "C:\Users\aaron\AppData\Local\Programs\Python\Python37\lib\ctypes\__init__.py", line 356, in __init__
    self._handle = _dlopen(self._name, mode)
OSError: [WinError 126] The specified module could not be found



TEST             | STATUS    | DURATION

feature_block.py | ✖ Failed  | 0 s

ALL              | ✖ Failed  | 0 s (accumulated)
Runtime: 0 s

In key.py I swapped ssl = ctypes.cdll.LoadLibrary(ctypes.util.find_library ('ssl') or 'libeay32') to ssl = ctypes.cdll.LoadLibrary('libssl-1_1-x64') and the error message changes to AttributeError: function 'BN_new' not found.

in test/functional/feature_block.py:831 in 161e83a5f8 outdated

 824 | @@ -824,7 +825,10 @@ def run_test(self):
 825 |          tx.vin.append(CTxIn(COutPoint(b64a.vtx[1].sha256, 0)))
 826 |          b64a = self.update_block("64a", [tx])
 827 |          assert_equal(len(b64a.serialize()), MAX_BLOCK_BASE_SIZE + 8)
 828 | -        self.sync_blocks([b64a], success=False, reject_reason='non-canonical ReadCompactSize(): iostream error')
 829 | +        if os.name != 'nt':
 830 | +            self.sync_blocks([b64a], success=False, reject_reason='non-canonical ReadCompactSize(): iostream error')
 831 | +        else:
 832 | +            self.sync_blocks([b64a], success=False, reject_reason='non-canonical ReadCompactSize(): iostream stream error')

MarcoFalke commented at 9:25 PM on September 9, 2018:

Could just shorten this to 'non-canonical ReadCompactSize'?

ken2812221 commented at 11:50 PM on September 9, 2018:

Done.

ken2812221 commented at 11:08 PM on September 9, 2018: contributor

@sipsorcery BN_new is not in libssl but in libeay on Windows

ken2812221 force-pushed on Sep 9, 2018

NicolasDorier commented at 2:36 AM on September 10, 2018: contributor

I am not testing the tests on AppVeyor now, just replicating his command line on my own box.

Wild guess: is it possible that the config file get created too late, after the node started? (as if you forgot to flush the data to the config file?)

I will continue to dig in.

ken2812221 commented at 2:44 AM on September 10, 2018: contributor

@NicolasDorier Can you try re-compile your bitcoind? Seems like you're using v0.15, but the tests is for v0.17. v0.15 can't read current test conf file properly and does not warn.

NicolasDorier commented at 3:50 AM on September 10, 2018: contributor

@ken2812221 I think that's why! Sorry for that, I compiled for Debug but was referencing Release... Recompiling now, but it should work.

NicolasDorier commented at 6:15 AM on September 10, 2018: contributor

@ken2812221 so the problem was just me having not linked the right exe... was stupid.

Now concerning wallet_multiwallet.py

PS C:\Sources\bitcoin>  python test\functional\test_runner.py --force wallet_multiwallet.py
Temporary test directory at C:\Users\NICOLA~1\AppData\Local\Temp/test_runner_20180910_150543
...................................................
wallet_multiwallet.py failed, Duration: 26 s

stdout:
2018-09-10T06:05:43.351000Z TestFramework (INFO): Initializing test directory C:\Users\NICOLA~1\AppData\Local\Temp\test_runner_20180910_150543\wallet_multiwallet_0
2018-09-10T06:05:58.478000Z TestFramework (INFO): Do not allow -zapwallettxes with multiwallet
2018-09-10T06:06:00.027000Z TestFramework (INFO): Do not allow -salvagewallet with multiwallet
2018-09-10T06:06:01.051000Z TestFramework (INFO): Do not allow -upgradewallet with multiwallet
2018-09-10T06:06:08.041000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "C:\Sources\bitcoin\test\functional\test_framework\test_framework.py", line 161, in main
    self.run_test()
  File "C:\Sources\bitcoin/test/functional/wallet_multiwallet.py", line 139, in run_test
    self.nodes[1].assert_start_raises_init_error(['-walletdir=' + competing_wallet_dir], exp_stderr, match=ErrorMatch.PARTIAL_REGEX)
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 264, in assert_start_raises_init_error
    self.wait_until_stopped()
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 231, in wait_until_stopped
    wait_until(self.is_node_stopped, timeout=timeout)
  File "C:\Sources\bitcoin\test\functional\test_framework\util.py", line 216, in wait_until
    if predicate():
  File "C:\Sources\bitcoin\test\functional\test_framework\test_node.py", line 222, in is_node_stopped
    "Node returned non-zero exit code (%d) when stopping" % return_code)
AssertionError: [node 1] Node returned non-zero exit code (3) when stopping
2018-09-10T06:06:08.094000Z TestFramework (INFO): Stopping nodes
[node 1] Cleaning up leftover process
[node 0] Cleaning up leftover process

With logs

debug.log

ken2812221 commented at 6:47 AM on September 10, 2018: contributor

@NicolasDorier That's a bug in bitcoind, so I disabled wallet_multiwallet.py to run on Appveyor for now. Maybe it's related to #14163.

NicolasDorier commented at 7:24 AM on September 10, 2018: contributor

Understood, so I think you should remove the changes of wallet_multiwallet.py for this PR. Then rebase them on a separate PR on top of #14163 fix, so we can properly test that part independently when we can.

ken2812221 commented at 7:33 AM on September 10, 2018: contributor

Actually, the probability that it would fail is about 50%, so the script can be tested. And the tests would fails only when nodes shutting down.

If there are more people think that I should revert those changes, I will do that.

NicolasDorier commented at 7:39 AM on September 10, 2018: contributor

ran several time, do not pass. Though it is not blocking for me, can as well reactivate the test once the fix is done later down the road.

tACK 529c5274de6fae782154c2845b6a691db46b0d4e

ken2812221 commented at 7:42 AM on September 10, 2018: contributor

Thanks for your review 👍

ken2812221 force-pushed on Sep 11, 2018

in test/util/bitcoin-util-test.py:80 in 529c5274de outdated

  76 | @@ -77,7 +77,7 @@ def bctest(testDir, testObj, buildenv):
  77 |      are not as expected. Error is caught by bctester() and reported.
  78 |      """
  79 |      # Get the exec names and arguments
  80 | -    execprog = os.path.join(buildenv["BUILDDIR"], "src", testObj["exec"] + buildenv["EXEEXT"])
  81 | +    execprog = os.path.join(os.environ.get('BITCOINPATH', '') or os.path.join(buildenv["BUILDDIR"], "src"), testObj["exec"] + buildenv["EXEEXT"])

MarcoFalke commented at 10:55 PM on September 11, 2018:

Hmm, this env var is not documented and makes the code a bit harder to read. Would it be too ugly to call mkdir src && mv ./bitcoin*.exe ./src in the appveyor after compile?

ken2812221 commented at 11:22 PM on September 11, 2018:

How about now?

ken2812221 force-pushed on Sep 11, 2018

MarcoFalke commented at 12:25 AM on September 12, 2018: member

Thanks, re-ACK

ken2812221 force-pushed on Sep 12, 2018

ken2812221 commented at 8:31 PM on September 12, 2018: contributor

@jnewbery Would you mind reviewing the test changes here. Most of code that changed in this PR are previously written by you.

jnewbery commented at 9:08 PM on September 12, 2018: member

Sure, I can review the tests: Make it possible to run functional tests on Windows commit, but it probably won't be until next week.

ken2812221 force-pushed on Sep 12, 2018

in test/functional/test_runner.py:49 in 52f95bbeb4 outdated

  40 | @@ -41,11 +41,16 @@
  41 |      CROSS = "x "
  42 |      CIRCLE = "o "
  43 |  
  44 | -if os.name == 'posix':
  45 | +if os.name != 'nt' or sys.getwindowsversion() >= (10, 0, 14393):
  46 | +    if os.name == 'nt':
  47 | +        import ctypes
  48 | +        kernel32 = ctypes.windll.kernel32
  49 | +        kernel32.SetConsoleMode(kernel32.GetStdHandle(-11), 7)

laanwj commented at 7:19 AM on September 13, 2018:

if you have to use ctypes directly here, with magic numbers, can you please at least add a comment about what the numbers here mean, what it is doing

in test/functional/test_runner.py:32 in 52f95bbeb4 outdated

  28 | @@ -29,7 +29,7 @@
  29 |  import logging
  30 |  
  31 |  # Formatting. Default colors to empty strings.
  32 | -BOLD, BLUE, RED, GREY = ("", ""), ("", ""), ("", ""), ("", "")
  33 | +BOLD, GREEN, RED, GREY = ("", ""), ("", ""), ("", ""), ("", "")

laanwj commented at 7:20 AM on September 13, 2018:

ACK on the color change to red/green, right in time for christmas

in test/functional/test_framework/authproxy.py:99 in 52f95bbeb4 outdated

  95 | @@ -102,6 +96,8 @@ def _request(self, method, path, postdata):
  96 |                     'User-Agent': USER_AGENT,
  97 |                     'Authorization': self.__auth_header,
  98 |                     'Content-type': 'application/json'}
  99 | +        if os.name == 'nt': # Windows somehow does not like to re-use connections

laanwj commented at 7:28 AM on September 13, 2018:

I guess this is meant as a temporary work-around until we find out why? (might want to add a comment in that regard) being able to re-use RPC connections is a big deal, it's not something we should simply accept as-is.

ken2812221 force-pushed on Sep 13, 2018

laanwj commented at 8:19 AM on September 13, 2018: member

utACK d5678479266bb087b37ee503000ab161d9e44664

ken2812221 force-pushed on Sep 16, 2018

ken2812221 commented at 11:42 PM on September 16, 2018: contributor

Update: Disabled 1 additional tests for now because of #14225 merged.

feature_notifications Bitcoin Core handle notifications in different thread, which can cause a race condition.
~mining_getblocktemplate_longpoll I'm not entirely sure what's going on here. Seems it doesn't take timeout=600 value.~ Fixed

ken2812221 force-pushed on Sep 17, 2018

ken2812221 commented at 12:43 AM on September 17, 2018: contributor

@MarcoFalke connection is still used in mining_getblocktemplate_longpoll.py. Please re-review.

ken2812221 force-pushed on Sep 17, 2018

tests: Make it possible to run functional tests on Windows 2148c36b6e

ken2812221 force-pushed on Sep 17, 2018

appveyor: Run functional tests on appveyor 661ac15a4a

ken2812221 force-pushed on Sep 17, 2018

MarcoFalke commented at 7:30 PM on September 17, 2018: member

utACK 661ac15a4aafae6ec1579721ef36ca2fde9c17b0

ken2812221 force-pushed on Sep 21, 2018

MarcoFalke merged this on Sep 24, 2018

MarcoFalke closed this on Sep 24, 2018

MarcoFalke referenced this in commit 990fc0de1a on Sep 24, 2018

ken2812221 deleted the branch on Sep 24, 2018

in test/functional/test_runner.py:288 in 661ac15a4a

 284 | @@ -264,7 +285,7 @@ def main():
 285 |  
 286 |      # Remove the test cases that the user has explicitly asked to exclude.
 287 |      if args.exclude:
 288 | -        exclude_tests = [re.sub("\.py$", "", test) + ".py" for test in args.exclude.split(',')]
 289 | +        exclude_tests = [re.sub("\.py$", "", test) + (".py" if ".py" not in test else "") for test in args.exclude.split(',')]

jnewbery commented at 9:48 PM on September 24, 2018:

I don't understand this change. The point of:

[re.sub("\.py$", "", test) + ".py"

is that if <test_name>.py or <test_name> is given, then it's normalized to <test_name>.py.

Your new version:

re.sub("\.py$", "", test) + (".py" if ".py" not in test else "")

essentially toggles, so <test_name>.py is changed to <test_name> and <test_name> is changed to <test_name>.py.

>>> test1 = 'test_name1.py'
>>> test2 = 'test_name2'
>>> for test in [test1,test2]:
...     print(re.sub("\.py$", "", test) + ".py") # original version
... 
test_name1.py
test_name2.py
>>> for test in [test1,test2]:
...     print(re.sub("\.py$", "", test) + (".py" if ".py" not in test else "")) # new version
... 
test_name1
test_name2.py

This breaks using -exclude=<test_name>.py

MarcoFalke commented at 10:29 PM on September 24, 2018:

The goal was to be able to specify --exclude "feature_notifications,wallet_multiwallet,wallet_multiwallet.py --usecli".

I think removing everything from the test_list that .startswith(item.split('.py')[0]) for any item in args.exclude.split(',') should solve all issues?

ken2812221 commented at 3:17 AM on September 25, 2018:

Oh, I didn't test that case. Should be fixed in #14316

jnewbery commented at 9:52 PM on September 24, 2018: member

tested ACK. I think there's one change that needs to be reverted. @ken2812221 - can you take a look for me?

MarcoFalke referenced this in commit 9b8bb5f140 on Sep 27, 2018

deadalnix referenced this in commit 1476f43a38 on May 6, 2020

MarcoFalke locked this on Sep 8, 2021