search

bcgov / von-network

A portable development level Indy Node network.
Apache License 2.0
161 stars 189 forks source link

TypeError: GenericMeta object argument after ** must be a mapping, not list #6

Closed benjsmi closed 6 years ago

benjsmi commented 6 years ago

Running this as is on an Ubuntu machine using Docker compose, here's the logs for Node1:

init_indy_node Node1 9418 80
Node-stack name is Node1
Client-stack name is Node1C
Generating keys for random seed b'cac2EE084B4AAaeE47F9D55f3B77c6F7'
Init local keys for client-stack
Public key is 28349f48e70b4013dd76dba0f1b4cdcaf6b05da015c95be4c95ccb496ef96264
Verification key is 968a23ea955a4df8833d813ea3e7d20e5901be20f7c794dc558986e8615c6a3c
Init local keys for node-stack
Public key is 28349f48e70b4013dd76dba0f1b4cdcaf6b05da015c95be4c95ccb496ef96264
Verification key is 968a23ea955a4df8833d813ea3e7d20e5901be20f7c794dc558986e8615c6a3c
BLS Public key is FufFb6gVM3ivGXpKbeSjCKBrbwbaFodvroUcX4wFh7rv8hvYtEfwSnVxDEG4VMPDvwfuugFDP1ajChv9PZpMWbqV1C9rRRNLcC2aLybXV5BVUJgFJrmZxPd8Dxbu75zLWkgvak2WfUSHUn4JazSgNzMkAWyHpFh611kYBmonWtmZMb
generate_indy_pool_transactions --nodes 4 --clients 0 --nodeNum 1 --ips 172.16.10.1,172.16.10.1,172.16.10.1,172.16.10.1
Generating keys for provided seed b'000000000000000000000000000Node1'
Init local keys for client-stack
Public key is f5a2927d4eb8e23cdd0167c2e786613993590dab50e6d68bc3821df3b8c34f1f
Verification key is ecbb3dd3a659f1e94d160fb2a77d85b92fda9de1b62c46e80ebf78735970056d
Init local keys for node-stack
Public key is f5a2927d4eb8e23cdd0167c2e786613993590dab50e6d68bc3821df3b8c34f1f
Verification key is ecbb3dd3a659f1e94d160fb2a77d85b92fda9de1b62c46e80ebf78735970056d
BLS Public key is 4N8aUNHSgjQVgkpm8nhNEfDf6txHznoYREg9kirmJrkivgL4oSEimFF6nsQ6M41QvhM2Z33nves5vfSn9n1UwNFJBYtWVnHYMATn76vLuL3zU88KyeAYcHfsih3He6UHcXDxcaecHVz6jhCYz1P2UZn2bDVruL5wXpehgBfBaLKm3Ba
Nodes will not run locally, so writing /etc/indy/indy.env
This node with name Node1 will use ports 9701 and 9702 for nodestack and clientstack respectively
BLS Public key is 37rAPpXVoxzKhz7d9gkUe52XuXryuLXoM6P6LbWDB7LSbG62Lsb33sfG7zqS8TK1MXwuCHj1FKNzVpsnafmqLG1vXN88rt38mNFs9TENzm4QHdBzsvCuoBnPH7rpYYDo9DZNJePaDvRvqJKByCabubJz3XXKbEeshzpz4Ma5QYpJqjk
BLS Public key is 3WFpdbg7C5cnLYZwFZevJqhubkFALBfCBBok15GdrKMUhUjGsk3jV6QKj6MZgEubF7oqCafxNdkm7eswgA4sdKTRc82tLGzZBd6vNqU8dupzup6uYUf32KTHTPQbuUM8Yk4QFXjEf2Usu2TJcNkdgpyeUSX42u5LqdDDpNSWUK5deC5
BLS Public key is 2zN3bHM1m4rLz54MJHYSwvqzPchYp8jkHswveCLAEJVcX6Mm1wHQD1SkPYMzUDTZvWvhuE6VNAkK3KxVeEmsanSmvjVkReDeBEMxeDaayjcZjFGPydyey1qxBHmTvAnBKoPydvuTAqx5f7YNNRAdeLmUi99gERUU7TD8KfAa6MpQ9bw
BLS Public key is 4N8aUNHSgjQVgkpm8nhNEfDf6txHznoYREg9kirmJrkivgL4oSEimFF6nsQ6M41QvhM2Z33nves5vfSn9n1UwNFJBYtWVnHYMATn76vLuL3zU88KyeAYcHfsih3He6UHcXDxcaecHVz6jhCYz1P2UZn2bDVruL5wXpehgBfBaLKm3Ba
BLS Public key is 37rAPpXVoxzKhz7d9gkUe52XuXryuLXoM6P6LbWDB7LSbG62Lsb33sfG7zqS8TK1MXwuCHj1FKNzVpsnafmqLG1vXN88rt38mNFs9TENzm4QHdBzsvCuoBnPH7rpYYDo9DZNJePaDvRvqJKByCabubJz3XXKbEeshzpz4Ma5QYpJqjk
BLS Public key is 3WFpdbg7C5cnLYZwFZevJqhubkFALBfCBBok15GdrKMUhUjGsk3jV6QKj6MZgEubF7oqCafxNdkm7eswgA4sdKTRc82tLGzZBd6vNqU8dupzup6uYUf32KTHTPQbuUM8Yk4QFXjEf2Usu2TJcNkdgpyeUSX42u5LqdDDpNSWUK5deC5
BLS Public key is 2zN3bHM1m4rLz54MJHYSwvqzPchYp8jkHswveCLAEJVcX6Mm1wHQD1SkPYMzUDTZvWvhuE6VNAkK3KxVeEmsanSmvjVkReDeBEMxeDaayjcZjFGPydyey1qxBHmTvAnBKoPydvuTAqx5f7YNNRAdeLmUi99gERUU7TD8KfAa6MpQ9bw
Generated genesis transaction file:
/home/indy/.indy-cli/networks/sandbox/pool_transactions_genesis
{"data":{"alias":"Node1","blskey":"4N8aUNHSgjQVgkpm8nhNEfDf6txHznoYREg9kirmJrkivgL4oSEimFF6nsQ6M41QvhM2Z33nves5vfSn9n1UwNFJBYtWVnHYMATn76vLuL3zU88KyeAYcHfsih3He6UHcXDxcaecHVz6jhCYz1P2UZn2bDVruL5wXpehgBfBaLKm3Ba","client_ip":"172.16.10.1","client_port":9702,"node_ip":"172.16.10.1","node_port":9701,"services":["VALIDATOR"]},"dest":"Gw6pDLhcBcoQesN72qfotTgFa7cbuqZpkX3Xo6pLhPhv","identifier":"Th7MpTaRZVRYnPiabds81Y","txnId":"fea82e10e894419fe2bea7d96296a6d46f50f93f9eeda954ec461b2ed2950b62","type":"0"}
{"data":{"alias":"Node2","blskey":"37rAPpXVoxzKhz7d9gkUe52XuXryuLXoM6P6LbWDB7LSbG62Lsb33sfG7zqS8TK1MXwuCHj1FKNzVpsnafmqLG1vXN88rt38mNFs9TENzm4QHdBzsvCuoBnPH7rpYYDo9DZNJePaDvRvqJKByCabubJz3XXKbEeshzpz4Ma5QYpJqjk","client_ip":"172.16.10.1","client_port":9704,"node_ip":"172.16.10.1","node_port":9703,"services":["VALIDATOR"]},"dest":"8ECVSk179mjsjKRLWiQtssMLgp6EPhWXtaYyStWPSGAb","identifier":"EbP4aYNeTHL6q385GuVpRV","txnId":"1ac8aece2a18ced660fef8694b61aac3af08ba875ce3026a160acbc3a3af35fc","type":"0"}
{"data":{"alias":"Node3","blskey":"3WFpdbg7C5cnLYZwFZevJqhubkFALBfCBBok15GdrKMUhUjGsk3jV6QKj6MZgEubF7oqCafxNdkm7eswgA4sdKTRc82tLGzZBd6vNqU8dupzup6uYUf32KTHTPQbuUM8Yk4QFXjEf2Usu2TJcNkdgpyeUSX42u5LqdDDpNSWUK5deC5","client_ip":"172.16.10.1","client_port":9706,"node_ip":"172.16.10.1","node_port":9705,"services":["VALIDATOR"]},"dest":"DKVxG2fXXTU8yT5N7hGEbXB3dfdAnYv1JczDUHpmDxya","identifier":"4cU41vWW82ArfxJxHkzXPG","txnId":"7e9f355dffa78ed24668f0e0e369fd8c224076571c51e2ea8be5f26479edebe4","type":"0"}
{"data":{"alias":"Node4","blskey":"2zN3bHM1m4rLz54MJHYSwvqzPchYp8jkHswveCLAEJVcX6Mm1wHQD1SkPYMzUDTZvWvhuE6VNAkK3KxVeEmsanSmvjVkReDeBEMxeDaayjcZjFGPydyey1qxBHmTvAnBKoPydvuTAqx5f7YNNRAdeLmUi99gERUU7TD8KfAa6MpQ9bw","client_ip":"172.16.10.1","client_port":9708,"node_ip":"172.16.10.1","node_port":9707,"services":["VALIDATOR"]},"dest":"4PS3EDQ3dW1tci1Bp6543CfuuebjFrg36kLAUcskGfaA","identifier":"TWwCRQRZ2ZHMJFn9TzLp7W","txnId":"aa5e817d7cc626170eca175822029339a444eb0ee8f0bd20d3b0b76e566fb008","type":"0"}
start_indy_node Node1 9701 9702
2018-03-09 17:14:47,390 | DEBUG    | __init__.py          (60) | register | Registered VCS backend: git
2018-03-09 17:14:47,413 | DEBUG    | __init__.py          (60) | register | Registered VCS backend: hg
2018-03-09 17:14:47,466 | DEBUG    | __init__.py          (60) | register | Registered VCS backend: svn
2018-03-09 17:14:47,467 | DEBUG    | __init__.py          (60) | register | Registered VCS backend: bzr
2018-03-09 17:14:48,380 | DEBUG    | selector_events.py   (53) | __init__ | Using selector: EpollSelector
2018-03-09 17:14:48,398 | DEBUG    | ledger.py            (201) | start | Starting ledger...
2018-03-09 17:14:48,411 | DEBUG    | ledger.py            (67) | recoverTree | Recovering tree from transaction log
2018-03-09 17:14:48,434 | DEBUG    | ledger.py            (82) | recoverTree | Recovered tree in 0.022596266004256904 seconds
2018-03-09 17:14:48,477 | DEBUG    | ledger.py            (201) | start | Starting ledger...
2018-03-09 17:14:48,485 | DEBUG    | ledger.py            (67) | recoverTree | Recovering tree from transaction log
2018-03-09 17:14:48,500 | DEBUG    | ledger.py            (82) | recoverTree | Recovered tree in 0.01505104498937726 seconds
2018-03-09 17:14:48,509 | INFO     | node.py              (2636) | initStateFromLedger | Node1 found state to be empty, recreating from ledger
2018-03-09 17:14:48,514 | INFO     | pool_manager.py      (394) | _order_node | Node1 node Node1 ordered, NYM Gw6pDLhcBcoQesN72qfotTgFa7cbuqZpkX3Xo6pLhPhv
2018-03-09 17:14:48,515 | INFO     | pool_manager.py      (394) | _order_node | Node1 node Node2 ordered, NYM 8ECVSk179mjsjKRLWiQtssMLgp6EPhWXtaYyStWPSGAb
2018-03-09 17:14:48,515 | INFO     | pool_manager.py      (394) | _order_node | Node1 node Node3 ordered, NYM DKVxG2fXXTU8yT5N7hGEbXB3dfdAnYv1JczDUHpmDxya
2018-03-09 17:14:48,516 | INFO     | pool_manager.py      (394) | _order_node | Node1 node Node4 ordered, NYM 4PS3EDQ3dW1tci1Bp6543CfuuebjFrg36kLAUcskGfaA
2018-03-09 17:14:48,535 | INFO     | node.py              (786) | _create_bls_bft | BLS: BLS Signatures will be used for Node Node1
2018-03-09 17:14:48,544 | INFO     | node.py              (2636) | initStateFromLedger | Node1 found state to be empty, recreating from ledger
2018-03-09 17:14:48,553 | INFO     | node.py              (612) | setPoolParams | Node1 updated its pool parameters: f 1, totalNodes 4, allNodeNames {'Node4', 'Node1', 'Node3', 'Node2'}, requiredNumberOfInstances 2, minimumNodes 3, quorums {'view_change_done': Quorum(3), 'view_change': Quorum(3), 'observer_data': Quorum(2), 'propagate_primary': Quorum(2), 'consistency_proof': Quorum(2), 'f': 1, 'prepare': Quorum(2), 'election': Quorum(3), 'bls_signatures': Quorum(3), 'propagate': Quorum(2), 'timestamp': Quorum(2), 'same_consistency_proof': Quorum(2), 'commit': Quorum(3), 'reply': Quorum(2), 'ledger_status': Quorum(2), 'checkpoint': Quorum(2)}
2018-03-09 17:14:48,607 | INFO     | plugin_loader.py     (118) | _load | plugin FirebaseStatsConsumer successfully loaded from module plugin_firebase_stats_consumer
2018-03-09 17:14:48,609 | DISPLAY  | replicas.py          (41) | grow | Node1 added replica Node1:0 to instance 0 (master)
2018-03-09 17:14:48,609 | DISPLAY  | replicas.py          (41) | grow | Node1 added replica Node1:1 to instance 1 (backup)
2018-03-09 17:14:48,610 | DEBUG    | plugin_helper.py     (23) | loadPlugins | Plugin loading started to load plugins from plugins_dir: /var/lib/indy/plugins
2018-03-09 17:14:48,611 | DEBUG    | plugin_helper.py     (28) | loadPlugins | Plugin directory created at: /var/lib/indy/plugins
2018-03-09 17:14:48,612 | DEBUG    | plugin_helper.py     (63) | loadPlugins | Total plugins loaded from plugins_dir /var/lib/indy/plugins are : 0
2018-03-09 17:14:48,647 | DEBUG    | ledger.py            (201) | start | Starting ledger...
2018-03-09 17:14:48,658 | DEBUG    | ledger.py            (67) | recoverTree | Recovering tree from transaction log
2018-03-09 17:14:48,689 | DEBUG    | ledger.py            (82) | recoverTree | Recovered tree in 0.03132294199895114 seconds
2018-03-09 17:14:48,701 | INFO     | node.py              (2636) | initStateFromLedger | Node1 found state to be empty, recreating from ledger
2018-03-09 17:14:48,702 | DEBUG    | ledger.py            (199) | start | Ledger already started.
2018-03-09 17:14:48,702 | DEBUG    | ledger.py            (199) | start | Ledger already started.
2018-03-09 17:14:48,703 | DEBUG    | ledger.py            (199) | start | Ledger already started.
2018-03-09 17:14:48,705 | DEBUG    | authenticator.py     (31) | start | Starting ZAP at inproc://zeromq.zap.1
2018-03-09 17:14:48,705 | DEBUG    | base.py              (72) | allow | Allowing 0.0.0.0
2018-03-09 17:14:48,705 | DEBUG    | base.py              (112) | configure_curve | Configure curve: *[/var/lib/indy/sandbox/keys/Node1/public_keys]
2018-03-09 17:14:48,707 | INFO     | stacks.py            (84) | start | CONNECTION: Node1 listening for other nodes at 0.0.0.0:9701
2018-03-09 17:14:48,708 | DEBUG    | authenticator.py     (31) | start | Starting ZAP at inproc://zeromq.zap.2
2018-03-09 17:14:48,708 | DEBUG    | base.py              (72) | allow | Allowing 0.0.0.0
2018-03-09 17:14:48,708 | DEBUG    | base.py              (112) | configure_curve | Configure curve: *[*]
2018-03-09 17:14:48,710 | INFO     | node.py              (853) | start | Node1 first time running...
2018-03-09 17:14:48,712 | INFO     | zstack.py            (584) | connect | CONNECTION: Node1 looking for Node4 at 172.16.10.1:9707
2018-03-09 17:14:48,714 | INFO     | zstack.py            (584) | connect | CONNECTION: Node1 looking for Node3 at 172.16.10.1:9705
2018-03-09 17:14:48,715 | INFO     | zstack.py            (584) | connect | CONNECTION: Node1 looking for Node2 at 172.16.10.1:9703
2018-03-09 17:14:49,121 | INFO     | keep_in_touch.py     (98) | _connsChanged | CONNECTION: Node1 now connected to Node4
2018-03-09 17:14:49,315 | INFO     | node.py              (1751) | preLedgerCatchUp | Node1 reverted 0 batches before starting catch up for ledger 0
2018-03-09 17:14:49,315 | INFO     | ledger_manager.py    (878) | mark_ledger_synced | CATCH-UP: Node1 completed catching up ledger 0, caught up 0 in total
2018-03-09 17:14:49,317 | INFO     | keep_in_touch.py     (98) | _connsChanged | CONNECTION: Node1 now connected to Node3
2018-03-09 17:14:49,332 | INFO     | looper.py            (273) | shutdown | Looper shutting down now...
Traceback (most recent call last):
  File "/usr/local/bin/start_indy_node", line 17, in <module>
    run_node(config, self_name, int(sys.argv[2]), int(sys.argv[3]))
  File "/usr/local/lib/python3.5/dist-packages/indy_node/utils/node_runner.py", line 34, in run_node
    looper.run()
  File "/usr/local/lib/python3.5/dist-packages/stp_core/loop/looper.py", line 290, in __exit__
    self.shutdownSync()
  File "/usr/local/lib/python3.5/dist-packages/stp_core/loop/looper.py", line 286, in shutdownSync
    self.loop.run_until_complete(self.shutdown())
  File "/usr/lib/python3.5/asyncio/base_events.py", line 387, in run_until_complete
    return future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "/usr/local/lib/python3.5/dist-packages/stp_core/loop/looper.py", line 276, in shutdown
    await self.runFut
  File "/usr/lib/python3.5/asyncio/futures.py", line 363, in __iter__
    return self.result()  # May raise too.
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/local/lib/python3.5/dist-packages/indy_node/utils/node_runner.py", line 34, in run_node
    looper.run()
  File "/usr/local/lib/python3.5/dist-packages/stp_core/loop/looper.py", line 260, in run
    return self.loop.run_until_complete(what)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 387, in run_until_complete
    return future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 274, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "/usr/local/lib/python3.5/dist-packages/stp_core/loop/looper.py", line 223, in runForever
    await self.runOnceNicely()
  File "/usr/local/lib/python3.5/dist-packages/stp_core/loop/looper.py", line 206, in runOnceNicely
    msgsProcessed = await self.prodAllOnce()
  File "/usr/local/lib/python3.5/dist-packages/stp_core/loop/looper.py", line 151, in prodAllOnce
    s += await n.prod(limit)
  File "/usr/local/lib/python3.5/dist-packages/indy_node/server/node.py", line 275, in prod
    c = await super().prod(limit)
  File "/usr/local/lib/python3.5/dist-packages/plenum/server/node.py", line 976, in prod
    c += await self.serviceNodeMsgs(limit)
  File "/usr/local/lib/python3.5/dist-packages/plenum/server/node.py", line 1010, in serviceNodeMsgs
    await self.processNodeInBox()
  File "/usr/local/lib/python3.5/dist-packages/plenum/server/node.py", line 1566, in processNodeInBox
    await self.nodeMsgRouter.handle(m)
  File "/usr/local/lib/python3.5/dist-packages/plenum/server/router.py", line 81, in handle
    res = self.handleSync(msg)
  File "/usr/local/lib/python3.5/dist-packages/plenum/server/router.py", line 70, in handleSync
    return self.getFunc(msg[0])(*msg)
  File "/usr/local/lib/python3.5/dist-packages/plenum/server/message_req_processor.py", line 50, in process_message_rep
    return handler.process(msg, frm)
  File "/usr/local/lib/python3.5/dist-packages/plenum/server/message_handlers.py", line 62, in process
    valid_msg = self.create(msg.msg, **params)
  File "/usr/local/lib/python3.5/dist-packages/plenum/server/message_handlers.py", line 75, in create
    return LedgerStatus(**msg)
TypeError: GenericMeta object argument after ** must be a mapping, not list

My environment:

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 16.04.4 LTS
Release:    16.04
Codename:   xenial

Linux kernel info:

$ uname -a
Linux ben-dev-machine 4.4.0-116-generic #140-Ubuntu SMP Mon Feb 12 21:23:04 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

Docker-compose info:

$ docker-compose version
docker-compose version 1.19.0, build 9e633ef
docker-py version: 2.7.0
CPython version: 2.7.13
OpenSSL version: OpenSSL 1.0.1t  3 May 2016

Docker info:

$ docker info
Containers: 6
 Running: 1
 Paused: 0
 Stopped: 5
Images: 334
Server Version: 17.12.1-ce
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 9b55aab90508bd389d7654c4baf173a981477d55
runc version: 9f9c96235cc97674e935002fc3d78361b696a69e
init version: 949e6fa
Security Options:
 apparmor
 seccomp
  Profile: default
Kernel Version: 4.4.0-116-generic
Operating System: Ubuntu 16.04.4 LTS
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 15.67GiB
Name: ***** censored *****
ID: JTGA:HCOJ:L6VQ:U7JT:UGNN:QYQ2:PCB7:V3RO:HAIC:LYYL:YAGF:6GFU
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false
benjsmi commented 6 years ago

Specifically, it seems like the problem occurs when the third node tries to join the network.

Connecting node 1 to node 2 works fine if I run them manually from the prompt using docker flags. Then when the third joins, it causes the first two to barf.

nrempel commented 6 years ago

Thanks for the info @benjsmi, the issue occurred when we stopped using a python virtual environment because a change to the pipenv utility changed and broke the build. (venv should be unnecessary in a docker container anyways). It seemed to be an issue with indy-plenum.

I never figured out what the issue was but reverting to using a virtual environment with a work-around for the pipenv change has fixed the build for now.

Let me know if the build still does not work for you.

benjsmi commented 6 years ago

Thanks!