Add expected payment proxy output logs

app/data/stacks/fixturenet-payments/README.md

@@ -1,6 +1,6 @@
 # fixturenet-payments
 
-Instructions to setup and deploy end-to-end fixturenet-payments stack using [laconic-stack-orchestrator](/README.md#install)
+Instructions to setup and deploy an end-to-end fixturenet-payments stack
 
 ## Setup
 

app/data/stacks/fixturenet-payments/demo.md

@@ -4,21 +4,22 @@ Stack components:
 * `ipld-eth-db` database for statediffed data
 * Local geth + lighthouse blockchain "fixturenet" running in statediffing mode
 * `ipld-eth-server` which runs an ETH RPC API and a GQL server; serves data from `ipld-eth-db`
-* A go-nitro node acting as the Nitro node for `ipld-eth-server`
+* A go-nitro deployment acting as the Nitro node for `ipld-eth-server`
-* A reverse payment proxy server that proxies requests to `ipld-eth-server`'s RPC endpoint; it talks to `ipld-eth-server`'s go-nitro node to validate payments required for configured RPC requests
+* A modified reverse payment proxy server (based on the one from go-nitro) that proxies requests to `ipld-eth-server`'s RPC endpoint; it talks to `ipld-eth-server`'s Nitro node to accept and validate payments required for configured RPC requests
 * A MobyMask v3 watcher that pays the `ipld-eth-server` for ETH RPC requests
-* A MobyMask v3 app that pays the watcher for GQL requests (queries + mutations)
+* A MobyMask v3 app that pays the watcher for reads (GQL queries) and writes
 * An example ERC20 Ponder app that pays the `ipld-eth-server` for ETH RPC requests
 
 ## Setup
 
-* On starting the stack, MobyMask watcher creates a payment channel with the `ipld-eth-server`'s go-nitro node. Check watcher logs and wait for the same:
+* On starting the stack, MobyMask watcher creates a payment channel with the `ipld-eth-server`'s Nitro node. Check watcher logs and wait for the same:
 
   ```bash
   docker logs -f $(docker ps -aq --filter name="mobymask-watcher-server")
 
   # Expected output:
-  # vulcanize:server Using rpcProviderEndpoint as chain URL for Nitro node +0ms
+  # vulcanize:server Peer ID: 12D3KooWKLqLWU82VU7jmsmQMruRvZWhoBoVsf1UHchM5Nuq9ymY
+  # vulcanize:server Using chain URL http://fixturenet-eth-geth-1:8546 for Nitro node
   # ...
   # ts-nitro:util:nitro Ledger channel created with id 0x65703ccdfacab09ac35367bdbe6c5a337e7a6651aad526807607b1c59b28bc1e
   # ...
@@ -59,7 +60,7 @@ Stack components:
   docker logs -f $(docker ps -aq --filter name="nitro-reverse-payment-proxy")
   ```
 
-* MetaMask wallet setup for running the MobyMask app:
+* MetaMask flask wallet setup for running the MobyMask app:
 
   * Get the geth node’s port mapped to host:
 
@@ -67,7 +68,7 @@ Stack components:
     docker port payments-fixturenet-eth-geth-1-1 8545
     ```
 
-  * In MetaMask Flask, add a custom network with the following settings:
+  * In MetaMask, add a custom network with the following settings:
 
     ```bash
     # Network name
@@ -123,17 +124,64 @@ Stack components:
   * Click on `Connect Wallet` to connect to MetaMask (make sure that the newly funded account is active)
   * Click on `Connect Snap` to install/connect snap
 
-* Perform `DIRECT FUND` with the preset amount; confirm the transaction and wait for a ledger channel to be created with the watcher
+* Perform `DIRECT FUND` with the preset amount and wait for the MetaMask confirmation prompt to appear; confirm the transaction and wait for a ledger channel to be created with the watcher
 
 * Perform `VIRTUAL FUND` with amount set to `10000` and wait for a payment channel to be created with the watcher
 
 * Perform phisher status check queries now that a payment channel is created:
-  * Check the watcher logs for received payments along with the GQL queries
-  * The watcher makes several ETH RPC requests to `ipld-eth-server` to fetch data required for satisfying the GQL request(s); check the payment proxy server logs for charged RPC requests (`eth_getBlockByHash`, `eth_getBlockByNumber`, `eth_getStorageAt`)
 
-* Change the amount besides `PAY` button to `>=100` for phisher reports next
+  * Check the watcher logs for received payments along with the GQL queries:
 
-* Perform a phisher report and check the watcher logs for received payments; the RPC mutation request is sent to geth node and is not charged
+    ```bash
+    # Expected output:
+    # ...
+    # laconic:payments Serving a paid query for 0x86804299822212c070178B5135Ba6DdAcFC357D3
+    # vulcanize:resolver isPhisher 0x98ae4f9e9d01cc892adfe6871e1db0287039e0c183d3b5bb31d724228c114744 0x2B6AFbd4F479cE4101Df722cF4E05F941523EaD9 TWT:ash1
+    # vulcanize:indexer isPhisher: db miss, fetching from upstream server
+    # laconic:payments Making RPC call: eth_chainId
+    # laconic:payments Making RPC call: eth_getBlockByHash
+    # laconic:payments Making RPC call: eth_chainId
+    # laconic:payments Making RPC call: eth_getStorageAt
+    ```
+
+  * The watcher makes several ETH RPC requests to `ipld-eth-server` to fetch data required for satisfying the GQL request(s); check the payment proxy server logs for charged RPC requests (`eth_getBlockByHash`, `eth_getBlockByNumber`, `eth_getStorageAt`):
+
+    ```bash
+    # Expected output:
+    # ...
+    # {"time":"2023-10-06T06:46:52.769009314Z","level":"DEBUG","msg":"Serving RPC request","method":"eth_chainId"}
+    # {"time":"2023-10-06T06:46:52.773006426Z","level":"DEBUG","msg":"Serving RPC request","method":"eth_getBlockByNumber"}
+    # {"time":"2023-10-06T06:46:52.811142054Z","level":"DEBUG","msg":"Request cost","cost-per-byte":1,"response-length":1480,"cost":1480,"method":"eth_getBlockByNumber"}
+    # {"time":"2023-10-06T06:46:52.811418494Z","level":"DEBUG","msg":"sent message","address":"0xAAA6628Ec44A8a742987EF3A114dDFE2D4F7aDCE","method":"receive_voucher"}
+    # {"time":"2023-10-06T06:46:52.812557482Z","level":"DEBUG","msg":"Received voucher","delta":5000}
+    # ...
+    # {"time":"2023-10-06T06:46:52.87525215Z","level":"DEBUG","msg":"Serving RPC request","method":"eth_getStorageAt"}
+    # {"time":"2023-10-06T06:46:52.882859654Z","level":"DEBUG","msg":"Request cost","cost-per-byte":1,"response-length":104,"cost":104,"method":"eth_getStorageAt"}
+    # {"time":"2023-10-06T06:46:52.882946485Z","level":"DEBUG","msg":"sent message","address":"0xAAA6628Ec44A8a742987EF3A114dDFE2D4F7aDCE","method":"receive_voucher"}
+    # {"time":"2023-10-06T06:46:52.884012641Z","level":"DEBUG","msg":"Received voucher","delta":5000}
+    # {"time":"2023-10-06T06:46:52.884032961Z","level":"DEBUG","msg":"Destination request","url":"http://ipld-eth-server:8081/"}
+    ```
+
+* Change the amount besides `PAY` button in debug panel to `>=100` for phisher reports next
+
+* Perform a phisher report and check the watcher logs for received payments; the RPC mutation request is sent to geth node and is not charged:
+
+  ```bash
+  # Expected output:
+  # ...
+  # vulcanize:libp2p-utils [6:50:2] Received a message on mobymask P2P network from peer: 12D3KooWRkxV9SX8uTUZYkbRjai4Fsn7yavB61J5TMnksixsabsP
+  # ts-nitro:engine {"msg":"Received message","_msg":{"to":"0xBBB676","from":"0x868042","payloadSummaries":[],"proposalSummaries":[],"payments":[{"amount":200,"channelId":"0x557153d729cf3323c0bdb40a36b245f98c2d4562933ba2182c9d61c5cfeda948"}],"rejectedObjectives":[]}}
+  # laconic:payments Received a payment voucher of 100 from 0x86804299822212c070178B5135Ba6DdAcFC357D3
+  # vulcanize:libp2p-utils Payment received for a mutation request from 0x86804299822212c070178B5135Ba6DdAcFC357D3
+  # vulcanize:libp2p-utils Transaction receipt for invoke message {
+  #   to: '0x2B6AFbd4F479cE4101Df722cF4E05F941523EaD9',
+  #   blockNumber: 232,
+  #   blockHash: '0x6a188722c102662ea48af3786fe9db0d4b6c7ab7b27473eb0e628cf95746a244',
+  #   transactionHash: '0x6521205db8a905b3222adc2b6855f9b2abc72580624d299bec2a35bcba173efa',
+  #   effectiveGasPrice: '1500000007',
+  #   gasUsed: '113355'
+  # }
+  ```
 
 * Check the watcher - ipld-eth-server payment channel status after a few requests:
 
@@ -169,10 +217,26 @@ Stack components:
   # 09:59:14.329 INFO  payment    Using payment channel 0x10f049519bc3f862e2b26e974be8666886228f30ea54aab06e2f23718afffab0
   ```
 
-* On starting the Ponder app, it creates a payment channel with the `ipld-eth-server`'s go-nitro node and then starts the historical sync service
+* On starting the Ponder app, it creates a payment channel with the `ipld-eth-server`'s Nitro node and then starts the historical sync service
 
 * The sync service makes several ETH RPC requests to the `ipld-eth-server` to fetch required data; check the payment proxy server logs for charged RPC requests (`eth_getBlockByNumber`, `eth_getLogs`)
 
+  ```bash
+  # Expected output:
+  # ...
+  # {"time":"2023-10-06T06:51:45.214478402Z","level":"DEBUG","msg":"Serving RPC request","method":"eth_getBlockByNumber"}
+  # {"time":"2023-10-06T06:51:45.22251171Z","level":"DEBUG","msg":"Request cost","cost-per-byte":1,"response-length":576,"cost":576,"method":"eth_getBlockByNumber"}
+  # {"time":"2023-10-06T06:51:45.222641963Z","level":"DEBUG","msg":"sent message","address":"0xAAA6628Ec44A8a742987EF3A114dDFE2D4F7aDCE","method":"receive_voucher"}
+  # {"time":"2023-10-06T06:51:45.224042391Z","level":"DEBUG","msg":"Received voucher","delta":5000}
+  # {"time":"2023-10-06T06:51:45.224061411Z","level":"DEBUG","msg":"Destination request","url":"http://ipld-eth-server:8081/"}
+  # {"time":"2023-10-06T06:51:45.242064953Z","level":"DEBUG","msg":"Serving RPC request","method":"eth_getLogs"}
+  # {"time":"2023-10-06T06:51:45.249118517Z","level":"DEBUG","msg":"Request cost","cost-per-byte":1,"response-length":61,"cost":61,"method":"eth_getLogs"}
+  # {"time":"2023-10-06T06:51:45.249189892Z","level":"DEBUG","msg":"sent message","address":"0xAAA6628Ec44A8a742987EF3A114dDFE2D4F7aDCE","method":"receive_voucher"}
+  # {"time":"2023-10-06T06:51:45.249743149Z","level":"DEBUG","msg":"Received voucher","delta":5000}
+  # {"time":"2023-10-06T06:51:45.249760631Z","level":"DEBUG","msg":"Destination request","url":"http://ipld-eth-server:8081/"}
+  # ...
+  ```
+
 * Export the payment channel id to a variable:
 
   ```bash