BF1 gets an error due to difference in the request_count for PFS

[agatsoh]

Description

- serial:
          name: "Check that IOUs exist after the payments"
          tasks:
            # Add a wait until all ious are processed correctly
            - wait: 100
            - assert_pfs_history: {source: 3, target: 0, request_count: 10}

Fails at - assert_pfs_history: {source: 3, target: 0, request_count: 10}

{
  "task": "<AssertPFSHistoryTask: {'source': 3, 'target': 0, 'request_count': 10}>",
  "event": "Task errored",
  "logger": "scenario_player.tasks.base",
  "level": "error",
  "greenlet_name": "orchestration",
  "timestamp": "2020-10-08 12:36:18.780219",
  "exception": "Traceback (most recent call last):\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/scenario_player/tasks/base.py\", line 126, in __call__\n    
  return_val = self._run(*args, **kwargs)\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/scenario_player/tasks/api_base.py\", line 45, in _run\n    
  method=self._method, url=url, json=self._request_params, timeout=self._timeout\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/requests/sessions.py\", line 530, in request\n    resp = self.send(prep, **send_kwargs)\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/requests/sessions.py\", line 643, in send\n    
  r = adapter.send(request, **kwargs)\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/requests/adapters.py\", line 449, in send\n    timeout=timeout\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/urllib3/connectionpool.py\", line 603, in urlopen\n    
  chunked=chunked)\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/urllib3/connectionpool.py\", line 383, in _make_request\n    
  httplib_response = conn.getresponse()\n  
  File \"/usr/local/lib/python3.7/http/client.py\", line 1336, in getresponse\n    
  response.begin()\n  
  File \"/usr/local/lib/python3.7/http/client.py\", line 306, in begin\n    
  version, status, reason = self._read_status()\n  
  File \"/usr/local/lib/python3.7/http/client.py\", line 267, in _read_status\n    
  line = str(self.fp.readline(_MAXLINE + 1), \"iso-8859-1\")\n  
  File \"/usr/local/lib/python3.7/socket.py\", line 589, in readinto\n    
  return self._sock.recv_into(b)\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/gevent/_ssl3.py\", line 567, in recv_into\n    
  return self.read(nbytes, buffer)\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/gevent/_ssl3.py\", line 390, in read\n    
  self._wait(self._read_event, timeout_exc=_SSLErrorReadTimeout)\n  
  File \"src/gevent/_hub_primitives.py\", line 317, in gevent._gevent_c_hub_primitives.wait_on_socket\n  
  File \"src/gevent/_hub_primitives.py\", line 322, in gevent._gevent_c_hub_primitives.wait_on_socket\n  
  File \"src/gevent/_hub_primitives.py\", line 304, in gevent._gevent_c_hub_primitives._primitive_wait\n  
  File \"src/gevent/_hub_primitives.py\", line 46, in gevent._gevent_c_hub_primitives.WaitOperationsGreenlet.wait\n  File \"src/gevent/_hub_primitives.py\", line 46, in gevent._gevent_c_hub_primitives.WaitOperationsGreenlet.wait\n  File \"src/gevent/_hub_primitives.py\", line 55, in gevent._gevent_c_hub_primitives.WaitOperationsGreenlet.wait\n  File \"src/gevent/_waiter.py\", line 151, in gevent._gevent_c_waiter.Waiter.get\n  
  File \"src/gevent/_greenlet_primitives.py\", line 61, in gevent._gevent_c_greenlet_primitives.SwitchOutGreenletWithLoop.switch\n  
  File \"src/gevent/_greenlet_primitives.py\", line 61, in gevent._gevent_c_greenlet_primitives.SwitchOutGreenletWithLoop.switch\n  
  File \"src/gevent/_greenlet_primitives.py\", line 65, in gevent._gevent_c_greenlet_primitives.SwitchOutGreenletWithLoop.switch\n  
  File \"src/gevent/_gevent_c_greenlet_primitives.pxd\", line 35, in gevent._gevent_c_greenlet_primitives._greenlet_switch\n
  gevent.timeout.Timeout: 300 seconds\n\n
  During handling of the above exception, another exception occurred:\n\n
  Traceback (most recent call last):\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/scenario_player/tasks/base.py\", line 138, in __call__\n    
  raise exception\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/scenario_player/tasks/base.py\", line 126, in __call__\n    
  return_val = self._run(*args, **kwargs)\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/scenario_player/tasks/api_base.py\", line 66, in _run\n    
  return self._process_response(response_dict)\n  
  File \"/home/devaki/Envs/raiden_env/lib/python3.7/site-packages/scenario_player/tasks/services.py\", line 215, in _process_response\n    
  f\"Expected request_count {exp_request_count} but got {actual_request_count}\"\n
  scenario_player.exceptions.ScenarioAssertionError: Expected request_count 10 but got 11"
}

scenario_player.exceptions.ScenarioAssertionError: Expected request_count 10 but got 11"

We could change the request_count to 11 in our case because we might be dealing with the PFS slightly differently with from the python client

Acceptance criteria

Tasks

• [ ]

[andrevmatos]

@agatsoh I just ran BF1 with latest master, it seem to be working now. Please, try again (don't forget to update dependencies and rebuild SDK and CLI).

[andrevmatos]

[agatsoh]

ok i will try again

[agatsoh]

@andrevmatos Unfortunately I tried a second time and I still get the same error

scenario_player.exceptions.ScenarioAssertionError: Expected request_count 10 but got 11

[andrevmatos]

@agatsoh Did you retry a previous run or restarted it in the middle for any reason? Are you double-sure you have re-built everything? This scenario includes a transfer which should fail before going to the PFS. This specific error only happens if it did try request the PFS (so +1 requests than should have been made). I ran the scenario 2x here on top of current master, and it didn't fail. Please, also re-check your environment is up-to-date.

[agatsoh]

Yes everything upto-date with the current master. This is what i did to install and build everything up

pnpm install
pnpm run build --filter raiden-ts
pnpm run build --filter raiden-cli
pnpm run build:bundle --filter raiden-cli

Let me know if I am missing something. Yes and it seems only specific to me so may be my network also plays a part in this. If you want you could close this and then we could open it if occurs again sometime.

[christianbrb]

@agatsoh Thanks a lot for documenting the issue :)

@andrevmatos Thanks for double-checking :)

Let's close the issue and check if it reoccurs during our nightly runs.