Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Restore testing with stack / nix-shell #195

Closed
wants to merge 1 commit into from
Closed

Conversation

fosskers
Copy link
Contributor

@fosskers fosskers commented Aug 29, 2018

TODO

  • Update Nix config to restore building
  • Debug stack / nix-shell test failures (related)
  • Debug nix-build test failures

Motivation

To further the move to Nix, this PR restores the ability to build and test with the various Nix tools.

@fosskers
Copy link
Contributor Author

fosskers commented Aug 29, 2018

Current test scores:

| Machine | ~stack test~ | ~nix-shell~ | ~nix-build~ |
|---------+--------------+-------------+-------------|
| Linux   | 6/10         | 8/10        | 0/3         |
| Mac     | 0/0          | 0/0         | 0/0         |

stack and nix-shell have the same type of failure, but it doesn't always happen. They look like:

  tests/PactContinuationSpec.hs:323:
  1) PactContinuation, pacts in dev server, testPactYield, when previous step yields value, resumes value
       uncaught exception: HttpException (HttpExceptionRequest Request {
         host                 = "localhost"
         port                 = 8080
         secure               = False
         requestHeaders       = [("Content-Type","application/json"),("User-Agent","haskell wreq-0.5.0.1")]
         path                 = "/api/v1/send"
         queryString          = ""
         method               = "POST"
         proxy                = Nothing
         rawBody              = False
         redirectCount        = 10
         responseTimeout      = ResponseTimeoutDefault
         requestVersion       = HTTP/1.1
       }
        (ConnectionFailure Network.Socket.connect: <socket: 30>: does not exist (Connection refused)))

but occur on different tests every time.

nix-build on the other hand fails in a completely different way:

tests/pact/tc.repl:24:27:Warning: Invalid field in schema object: "handle"
tests/pact/tc.repl:116:4:Warning: Cannot unify: (bool,integer)
tests/pact/leftpad.repl:72:0: Execution aborted, hash not blessed for module "impure": "7014a0cfff7f00000400000001000000dd18bef0ff7f000058d44100420000007014a0cfff7f00000200000003000000dd18bef0ff7f000058d4410042000000"
 at tests/pact/leftpad.repl:13:19: Execution aborted, hash not blessed for module "impure": "7014a0cfff7f00000400000001000000dd18bef0ff7f000058d44100420000007014a0cfff7f00000200000003000000dd18bef0ff7f000058d4410042000000"
 at tests/pact/leftpad.repl:13:19: (insert <deftable foo> "b" <object>)
 at tests/pact/leftpad.repl:27:26: (ins "b" <object>)
 at tests/pact/leftpad.repl:72:0: (dep-impure "b" 1)
hspec: user error (tests/pact/leftpad.repl:13:19: Execution aborted, hash not blessed for module "impure": "7014a0cfff7f00000400000001000000dd18bef0ff7f000058d44100420000007014a0cfff7f00000200000003000000dd18bef0ff7f000058d4410042000000")

Note that these failures are on Linux. Mac results forthcoming.

@fosskers
Copy link
Contributor Author

Mac failure, using nix-build:

  tests/PactContinuationSpec.hs:437:
  17) PactContinuation, pacts in dev server, testTwoPartyEscrow, throws error when final price negotiated up
       uncaught exception: ErrorCall (Received empty poll. Timeout in retrying.
       CallStack (from HasCallStack):
         error, called at tests/Utils/TestRunner.hs:96:40 in main:Utils.TestRunner)

  tests/PactContinuationSpec.hs:441:
  18) PactContinuation, pacts in dev server, testTwoPartyEscrow, when both debtor and creditor finish together, finishes escrow if final price stays the same or negotiated down
       uncaught exception: HttpException (HttpExceptionRequest Request {
         host                 = "localhost"
         port                 = 8080
         secure               = False
         requestHeaders       = [("Content-Type","application/json"),("User-Agent","haskell wreq-0.5.0.1")]
         path                 = "/api/v1/send"
         queryString          = ""
         method               = "POST"
         proxy                = Nothing
         rawBody              = False
         redirectCount        = 10
         responseTimeout      = ResponseTimeoutDefault
         requestVersion       = HTTP/1.1
       }
        (InternalException Network.Socket.recvBuf: resource vanished (Connection reset by peer)))

  tests/PactContinuationSpec.hs:33:
  19) PactContinuation, pacts in dev server, testNestedPacts, throws error when multiple defpact executions occur in same transaction
       uncaught exception: ErrorCall (Received empty poll. Timeout in retrying.
       CallStack (from HasCallStack):
         error, called at tests/Utils/TestRunner.hs:96:40 in main:Utils.TestRunner)

There were 19 failures in total, these 3 are just a sample.

@fosskers
Copy link
Contributor Author

| Machine | ~stack test~ | ~nix-shell~ | ~nix-build~ |
|---------+--------------+-------------+-------------|
| Linux   | 8/10         | 9/10        | 0/3         |
| Mac     | 0/0          | 0/5         | 0/1         |

With concurrency activated, the tests mostly don't time out anymore. However, we do see quite a lot of:

    testPactYield
      when previous step yields value
logger got exception: thread blocked indefinitely in an MVar operation
logger got exception: thread blocked indefinitely in an MVar operation
logger got exception: thread blocked indefinitely in an MVar operation
logger got exception: thread blocked indefinitely in an MVar operation
logger got exception: thread blocked indefinitely in an MVar operation

That log message appears throughout, even when the tests all succeed. When the stars align, enough blocks occur and the tests hang.

@fosskers
Copy link
Contributor Author

The MVar messages no longer appear, but nix-build still fails in the same way it has been.

@fosskers
Copy link
Contributor Author

fosskers commented Aug 30, 2018

leftpad.repl expects whatever it's authenticating to have a fixed hash. However, with every run of run-build, the real hash is random. Here's a sample:

a05257f2ff7f0000a80395f0ff7f000069a80b004200000040aa0b0042000000280595f0ff7f000031aa0b004200000040aa0b0042000000100ea0cfff7f0000
a05257f2ff7f0000a80395f0ff7f000069080c0042000000400a0c0042000000280595f0ff7f0000310a0c0042000000400a0c0042000000100ea0cfff7f0000

2e19bef0ff7f0000f91fbef0ff7f0000d087da0042000000f91bbef0ff7f0000e887da0042000000a11bbef0ff7f0000a919bef0ff7f00005088da0042000000
2e19bef0ff7f0000f91fbef0ff7f000010259c0042000000f91bbef0ff7f000028259c0042000000a11bbef0ff7f0000a919bef0ff7f000090259c0042000000
2e19bef0ff7f0000f91fbef0ff7f000060cfca0042000000f91bbef0ff7f000078cfca0042000000a11bbef0ff7f0000a919bef0ff7f00000070ca0042000000

a951150042000000580195f0ff7f00000054150042000000100ea0cfff7f00000200000006000000d819bef0ff7f0000d828c400420000000129c40042000000
a9f1060042000000580195f0ff7f000000f4060042000000100ea0cfff7f00000200000006000000d819bef0ff7f0000609f950042000000899f950042000000

1868a0cfff7f0000b8a80800420000004019bef0ff7f00002e19bef0ff7f0000f91fbef0ff7f000008c29b0042000000f91bbef0ff7f000020c29b0042000000

d01f9a0042000000381e95f0ff7f0000dc1e9a0042000000f914bef0ff7f00000fa43c0042000000782095f0ff7f000092a33c004200000079a33c0042000000

b1d35a0042000000f0d35a0042000000280595f0ff7f000052d35a0042000000f0d35a0042000000100ea0cfff7f000004000000030000001f1fbef0ff7f0000

@fosskers
Copy link
Contributor Author

fosskers commented Sep 4, 2018

Removing leftpad.repl from the tests directory (thereby disabling it as a test), we successfully proceed to the next stage of tests. However, every following test that relies on hashing also fails, all citing hash mismatches.

@mightybyte
Copy link
Contributor

@fosskers Hmmm, any chance you can dig into the code to see what's the source of the non-determinism?

@fosskers
Copy link
Contributor Author

fosskers commented Sep 4, 2018

That's the plan.

@fosskers
Copy link
Contributor Author

fosskers commented Sep 4, 2018

Among many others, the following REPL tests fail with nix-build:

(expect "repl starts with empty hash" (hash "") (tx-hash))
(env-hash (hash "hello"))
(expect "hash roundtrip" (hash "hello") (tx-hash))

This is very telling. It's essentially:

"The repl should start with an empty hash". Sorry, I don't.
"Okay, I'm overriding the REPL's 'transaction hash' to be the hash of 'hello'" Gotcha.
"Alright, (hash "hello") should be equal to what I just set it to..." Sorry, it's not.

@fosskers
Copy link
Contributor Author

fosskers commented Sep 4, 2018

My lord.

(expect "basic hash sanity - empty string" (hash "") (hash ""))
(expect "basic hash sanity - hello" (hash "hello") (hash "hello"))
  tests/PactTestsSpec.hs:55: 
  21) PactTests, pact tests, tests/pact/hash.repl, basic hash sanity - empty string
       tests/pact/hash.repl:1:0: FAILURE: basic hash sanity - empty string: expected "d0647cd0ff7f0000c8eb0c0042000000f834b9f1ff7f000052eb0c004200000028cd9af1ff7f000019ed87004200000018ed0c004200000032ed0c0042000000", received "e95402d0ff7f000032ed0c0042000000881da0cfff7f0000e95402d0ff7f000048ee0c0042000000c8eca1d0ff7f0000000000000000000018d8c0f1ff7f0000"

  tests/PactTestsSpec.hs:55: 
  22) PactTests, pact tests, tests/pact/hash.repl, basic hash sanity - hello
       tests/pact/hash.repl:2:0: FAILURE: basic hash sanity - hello: expected "1868a0cfff7f0000718309004200000081ef0c004200000099efe20042000000d8fbe0cfff7f0000b0ef0c004200000090ef0c004200000071f2e00042000000", received "302395f0ff7f0000f0300b0042000000582395f0ff7f000008310b0042000000100ea0cfff7f00000300000005000000101bbef0ff7f0000aa221d0142000000"

@fosskers
Copy link
Contributor Author

fosskers commented Sep 4, 2018

I'm going to revisit this tomorrow.

@fosskers
Copy link
Contributor Author

fosskers commented Sep 7, 2018

@emilypi and I discovered that forcing Pact/Types/Hash.hs to use @slpopejoy 's implementation of hash will always succeed in nix-build. Forcing it to use the version provided by blake2 will fail as seen so far.

@fosskers
Copy link
Contributor Author

fosskers commented Sep 10, 2018

Pinging @slpopejoy @mightybyte to solicit feedback.

As reported in the comment above, the blake2 library loses consistent hashing behaviour within our test suites, but only when done inside nix-build. Things work just fine with stack / nix-shell.

The way @emilypi and I see it, we could:

  • dive into blake2's custom C code + the corresponding FFI code to debug, or;
  • test other pure-Haskell (no C-bits!) implementations for correctness / performance vs both blake2 and Stu's port, say as found in cryptonite.

The blake2 library doesn't declare any non-Haskell deps, nor does its Nix derivation (grep for it). However, its actual C files do have some CPP'd conditional imports, so that's a possible avenue of exploration.

Question for @slpopejoy : do we have a hard-requirement on the blake2 haskell library specifically? I see that its last upload was 2 years ago.

@mightybyte
Copy link
Contributor

@fosskers We just discussed this with @slpopejoy. The official word is that we have a hard requirement to call out to a low-level C library. The blake2 package is our first choice due to it being very lightweight.

@fosskers
Copy link
Contributor Author

fosskers commented Sep 11, 2018

Ok cool. Relative to blake2, cryptonite does pull in foundation, but otherwise it seems like a fairly small addition to our dep graph. lens, as always, is a tank, and is probably an easier target if bloat is an issue:

deps

Dropping yaml would drop conduit, we could probably sneak out trifecta, etc etc.

cryptonite does have cbits, so I'm assuming it's performant. We'll find out.

@fosskers
Copy link
Contributor Author

For now I'm going to alter this PR to address only the issues surrounding the concurrency flags used in the test suites. A subsequent PR will be called something like "Explore Cryptonite" with the specific purpose of replacing blake2 and benchmarking everything.

@emilypi
Copy link
Member

emilypi commented Sep 11, 2018

Sounds good @fosskers 😄

@fosskers fosskers changed the title [WIP] Fix Nix builds Restore testing with stack / nix-shell Sep 11, 2018
@fosskers
Copy link
Contributor Author

Rebased.

" could not be cancelled.")
_ -> return ()

stopServer (asyncServer, _, _) = cancel asyncServer
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If @slpopejoy signs off on this, looks like it's good to go.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@LindaOrtega made this suggestion originally. This change prevents a few sporadic connection failures in the tests.

@fosskers
Copy link
Contributor Author

Rebased onto master to fix Travis.

- Also avoid server cancelling in tests, or else certain requests
  sporadically fail.
@fosskers
Copy link
Contributor Author

Rebased to fix merge conflicts.

@vaibhavsagar
Copy link
Contributor

vaibhavsagar commented Sep 14, 2018

Some observations:

  1. The hash test failure has nothing to do with reflex-platform or our specific fork of Nixpkgs; I was able to reproduce both the test failure and the expected successful build in a nix-shell after switching to a recent revision of Nixpkgs 18.03 (this is available in the rip-out-reflex-platform branch)

  2. I wrote a HashSpec which just hashes the empty string and "hello" twice and compares the computed hashes. This test passes.

  3. We overrode the checkPhase and installPhase to produce a successful build despite the failing tests, and we observed that the mismatched hashes are extremely odd. Here's a snippet:

  tests/PactTestsSpec.hs:55: 
  21) PactTests, pact tests, tests/pact/a.repl, basic hash sanity - empty string
       tests/pact/a.repl:1:0: FAILURE: basic hash sanity - empty string: expected "915e0f004200000040acbcc4307f0000d1f69b00420000000e000000000000001a00000000000000fc000000000000001a0000000000000000411eb2307f0000", received "f99488b3307f000000411eb2307f00009190080042000000009008004200000000411eb2307f00008190080042000000209588b3307f0000f08488b3307f0000"

  tests/PactTestsSpec.hs:55: 
  22) PactTests, pact tests, tests/pact/a.repl, basic hash sanity - hello
       tests/pact/a.repl:2:0: FAILURE: basic hash sanity - hello: expected "a19108004200000060cf040042000000e0cf040042000000f08488b3307f000010ba4fb3307f0000fe0000000000000010ba4fb3307f00000200000000000000", received "3993080042000000809208004200000000411eb2307f0000199308004200000060cf040042000000e0cf040042000000b09008004200000010ba4fb3307f0000"

  tests/PactTestsSpec.hs:55: 
  23) PactTests, pact tests, tests/pact/hash.repl, repl starts with empty hash
       tests/pact/hash.repl:1:0: FAILURE: repl starts with empty hash: expected "e0700b0042000000c902b2c4307f000038547cb2307f00006500000000000000706dbec4307f0000f9fd0300420000001b6c030042000000c902b2c4307f0000", received "d96a000042000000d89dbdc4307f00006811560042000000c0a3bdc4307f0000224d85b3307f0000d96a000042000000199be8c4307f00004f6b000042000000"

  tests/PactTestsSpec.hs:55: 
  24) PactTests, pact tests, tests/pact/hash.repl, hash roundtrip
       tests/pact/hash.repl:3:0: FAILURE: hash roundtrip: expected "2a760b004200000011760b00420000008c2d1a0042000000199be8c4307f0000d0241a004200000051ce0c004200000000411eb2307f000008780b0042000000", received "89720b0042000000f9710b004200000079720b0042000000199be8c4307f0000d0241a004200000051ce0c0042000000df720b004200000010fc1db2307f0000"

a.repl is taken straight from #195 (comment). There are a couple of strange things here: Why is the expected hash for "hello" different between tests, and why do none of the hashes for the empty string match the actual hash of the empty string provided by the pact REPL?

pact> (hash "")
"786a02f742015903c6c6fd852552d272912f4740e15847618a86e217f71f5419d25e1031afee585313896444934eb04b903a685b1448b755d56f701afe9be2ce"
  1. I tried to reproduce this failure with just blake2 in a fresh project, and I didn't run into any issues.

  2. I've ruled out the cached copy of blake2 by building a fresh copy with callCabal2nix "blake2" (fetchFromGitHub {...}) and that exhibits the same issue.

  3. Ryan and I spent some time yesterday tweaking the configureFlags and building manually with Cabal and we didn't find a combination of them that didn't trigger the test failure, so we've ruled out the nix-build process and the generic-builder.nix as the source of the problem.

  4. Ryan observed that the entropy in the mismatched hashes is too low for them to actually be hashes, and that they seem more like random snippets from memory. It doesn't seem like a concurrency issue because we ran the test suite with -j 1 and it failed in exactly the same way.

Currently I'm trying to cut down the pact repo to a more manageable size to reduce cycle time and see if I can make the issue easier to see.

@vaibhavsagar
Copy link
Contributor

I have good news and bad news.

Good news: This issue is now easily reproducible in a nix-shell:

$ git clone https://github.com/kadena-io/pact
$ cd pact
$ cat > tests/HashSpec.hs << EOF
{-# LANGUAGE OverloadedStrings #-}
module HashSpec (spec) where

import Test.Hspec

import Pact.Types.Hash (hash)

spec :: Spec
spec = do
  describe "hashing" $ do
    it "hashes the empty string correctly" $ do
      let foo = hash ""
      let bar = hash ""
      foo `shouldBe` bar
    it "hashes \"hello\" correctly" $ do
      let foo = hash "hello"
      let bar = hash "hello"
      foo `shouldBe` bar
EOF

$ nix-shell -A shells.ghc
[nix-shell]$ runhaskell Setup.hs configure --enable-tests
<...>
[nix-shell]$ runhaskell Setup.hs build
<...>
[nix-shell]$ runhaskell Setup.hs test

Bad news: I tried reproducing the failure with Stack but all tests pass, even with this change.

@fosskers
Copy link
Contributor Author

fosskers commented Sep 14, 2018

@vaibhavsagar your hspec tests there do indeed fail in nix-shell?

Ryan observed that the entropy in the mismatched hashes is too low for them to actually be hashes, and that they seem more like random snippets from memory.

That's fascinating.

@vaibhavsagar
Copy link
Contributor

@fosskers after making the change to HashSpec.hs: that test itself passes, but its existence causes other tests to start failing, which points to something wonky happening with memory.

@vaibhavsagar
Copy link
Contributor

vaibhavsagar commented Sep 17, 2018

Two more interesting observations:

  1. I can 100% rule Nix out as the cause of this test failure: I am able to reproduce it with only cabal new-test as follows:
$ git clone --recursive -b minimal-failure-repro https://github.com/vaibhavsagar/pact.git
$ cd pact
$ git checkout 1d2320d
$ nix-shell -p 'haskellPackages.ghcWithPackages (p: [ p.cabal-install ])'
$ LIBRARY_PATH=$(nix-build --no-out-link -E '(import <nixpkgs> {}).zlib')/lib:$LIBRARY_PATH C_INCLUDE_PATH=$(nix-build --no-out-link -E '(import <nixpkgs> {}).zlib.dev')/include:$C_INCLUDE_PATH cabal new-test

The Nix commands are only used because I was running this on NixOS, but I imagine it would work the same on another Linux distro.

  1. Removing wreq from the dependencies of the test suite makes it pass. We compared the output of ghc-pkg list between the cabal sandboxes, and here are the dependencies introduced by adding wreq in:
-    RSA-2.3.0
-    SHA-1.6.4.2
-    asn1-encoding-0.9.5
-    asn1-parse-0.9.4
-    asn1-types-0.3.2
-    authenticate-oauth-1.6
-    base64-bytestring-1.0.0.1
-    basement-0.0.4
-    byteable-0.1.1
-    connection-0.2.8
-    cookie-0.4.3
-    crypto-api-0.13.3
-    crypto-pubkey-types-0.4.3
-    cryptohash-0.11.9
-    cryptonite-0.24
-    entropy-0.3.8
-    foundation-0.0.17
-    hourglass-0.2.11
-    http-client-0.5.10
-    http-client-tls-0.3.5.3
-    http-types-0.9.1
-    memory-0.14.11
-    mime-types-0.1.0.7
-    network-2.6.3.6
-    network-uri-2.6.1.0
-    pem-0.2.4
-    psqueues-0.2.5.0
-    socks-0.5.6
-    streaming-commons-0.1.19
-    tls-1.4.1
-    wreq-0.5.2.0
-    x509-1.7.3
-    x509-store-1.6.6
-    x509-system-1.6.6
-    x509-validation-1.6.10
-    zlib-0.6.1.2

We suspected that the inclusion of cryptonite or cryptohash might be causing the failures, but we added each of those as dependencies and the test suite still passed so something else must be going on.

Edit: I tried adding all these dependencies except wreq to the build-depends of the test suite and the tests still passed, so if this is what's actually happening it is an issue with wreq itself and not one of its dependencies.

@fosskers
Copy link
Contributor Author

@vaibhavsagar re: your blake2 PR. Does that mean that nix is invoking different GHC optimization / inlining behaviour?

@vaibhavsagar
Copy link
Contributor

No, this failure can be reproduced with Stack as well: haskell/cabal#5583 (comment). I think it's interesting that nix-build seems to trigger this failure consistently, but I think in this case that has turned out to be a good thing.

@mightybyte
Copy link
Contributor

Closing. These changes were superseded by other changes and the build is working now.

@mightybyte mightybyte closed this Nov 1, 2018
@fosskers fosskers deleted the fix-nix-builds branch October 7, 2019 21:24
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants