Merge pull request #23 from Permissionless-Software-Foundation/ct-unstable

fix(logging): Improved logging

bin/server.js

@@ -59,6 +59,7 @@ class Server {
     try {
       // Create an Express instance.
       const app = express()
+      app.set('trust proxy', true)
 
       const x402Settings = getX402Settings()
       const basicAuthSettings = getBasicAuthSettings()
@@ -183,7 +184,10 @@ class Server {
 
       // Request logging middleware
       app.use((req, res, next) => {
-        wlogger.info(`${req.method} ${req.path}`)
+        wlogger.info(`${req.method} ${req.path}`, {
+          client_ip: req.ip,
+          remote_address: req.socket?.remoteAddress || null
+        })
         next()
       })
 
@@ -246,6 +250,11 @@ class Server {
         wlogger.info(`Server started on port ${this.config.port}`)
       })
 
+      // Explicit timeout settings reduce stale keep-alive socket reuse races.
+      this.server.keepAliveTimeout = this.config.serverKeepAliveTimeoutMs
+      this.server.headersTimeout = this.config.serverHeadersTimeoutMs
+      this.server.requestTimeout = this.config.serverRequestTimeoutMs
+
       this.server.on('error', (err) => {
         console.error('Server error:', err)
         wlogger.error('Server error:', err)

dev-docs/update-logs/2026-03-16.md

@@ -0,0 +1,21 @@
+# 2026-03-16 Update Log
+
+## Summary
+
+Reduced noisy error logging for common SLP transaction misses in the `/v6/slp/txid` path.
+
+## Changes Made
+
+- Updated `src/use-cases/slp-use-cases.js` in `getTxid()`:
+  - Added a guard for expected missing-record errors (`404` + `Key not found in database`).
+  - Skips `wlogger.error()` for that specific, common case.
+  - Still rethrows the error so API response behavior is unchanged.
+- Updated `src/controllers/rest-api/slp/controller.js` in `handleError()`:
+  - Added the same guard to suppress duplicate error-level logs for the same expected case.
+  - Keeps normal error logging for all other errors.
+
+## Outcome
+
+- The common "Key not found in database" case no longer pollutes error logs.
+- Unexpected failures continue to be logged at error level.
+- Client-facing status and error message behavior remains unchanged.

dev-docs/update-logs/2026-03-17.md

@@ -0,0 +1,60 @@
+# 2026-03-17 Update Log
+
+## Summary
+
+Enhanced REST request logging to capture client network identity in Winston logs and enabled proxy-aware IP resolution.
+
+## Changes Made
+
+- Updated `bin/server.js`:
+  - Set Express proxy handling with `app.set('trust proxy', true)`.
+  - Kept the current Winston request message format (`"${req.method} ${req.path}"`).
+  - Added structured Winston metadata fields to request logs:
+    - `client_ip` from `req.ip`
+    - `remote_address` from `req.socket.remoteAddress`
+
+## Useful Fields Available for REST Request Logging
+
+- Routing and request basics:
+  - `method` (`req.method`)
+  - `path` (`req.path`)
+  - `original_url` (`req.originalUrl`)
+  - `query` (`req.query`)
+- Client network identity:
+  - `client_ip` (`req.ip`)
+  - `forwarded_ips` (`req.ips`, when behind one or more proxies)
+  - `remote_address` (`req.socket.remoteAddress`)
+- HTTP and transport:
+  - `protocol` (`req.protocol`)
+  - `secure` (`req.secure`)
+  - `http_version` (`req.httpVersion`)
+  - `host` (`req.get('host')`)
+  - `origin` (`req.get('origin')`)
+  - `referer` (`req.get('referer')`)
+  - `user_agent` (`req.get('user-agent')`)
+- Request/response performance and size:
+  - `status_code` (`res.statusCode`, from `res.on('finish')`)
+  - `duration_ms` (elapsed time between request start and response finish)
+  - `request_size_bytes` (`req.get('content-length')`)
+  - `response_size_bytes` (`res.getHeader('content-length')`)
+- App-specific request context in this codebase:
+  - `basic_auth_valid` (`req.locals.basicAuthValid`)
+  - x402 decision/bypass status (derived from middleware path and config)
+
+## Already Logging
+
+- In Winston request logs:
+  - `message` with method + path (for example `GET /v6/full-node/blockchain/getBlockCount`)
+  - `client_ip`
+  - `remote_address`
+  - `timestamp` (from Winston timestamp formatter)
+  - `level`
+- In console endpoint logs:
+  - Request line with method, path, and `req.ip`
+  - Response line with method, path, and final `res.statusCode`
+
+## Outcome
+
+- Request logs now preserve existing behavior while adding IP attribution fields.
+- `trust proxy` ensures `req.ip` is proxy-aware when the server is deployed behind a reverse proxy.
+- The project now has a documented list of high-value request fields for future logging expansion.

package-lock.json

@@ -9,12 +9,12 @@
       "version": "7.0.0",
       "license": "MIT",
       "dependencies": {
-        "@psf/bch-js": "7.1.11",
+        "@psf/bch-js": "7.1.14",
         "axios": "1.7.7",
         "cors": "2.8.5",
         "dotenv": "16.3.1",
         "express": "5.1.0",
-        "minimal-slp-wallet": "7.1.4",
+        "minimal-slp-wallet": "7.1.5",
         "psffpp": "1.2.1",
         "slp-token-media": "1.2.10",
         "winston": "3.11.0",
@@ -858,9 +858,9 @@
       }
     },
     "node_modules/@psf/bch-js": {
-      "version": "7.1.11",
-      "resolved": "https://registry.npmjs.org/@psf/bch-js/-/bch-js-7.1.11.tgz",
-      "integrity": "sha512-gDJCaY2aG8EtUWcR9D4tbiyM1BkHd7gkuO7NRaLpwdbSrnU51lyPr69mjQLKOcVlL+aXdJsOjL5pm15t4zq18w==",
+      "version": "7.1.14",
+      "resolved": "https://registry.npmjs.org/@psf/bch-js/-/bch-js-7.1.14.tgz",
+      "integrity": "sha512-B/NXuxSoOHgMR0tHyY8qpXN3VDATeBhd6qhasJsiEjb22IGIjsXsdJ0oZR2DLnn/1UA+94+XJNyVz2UlcaqEpw==",
       "license": "MIT",
       "dependencies": {
         "@chris.troutner/bip32-utils": "1.0.5",
@@ -6475,13 +6475,13 @@
       }
     },
     "node_modules/minimal-slp-wallet": {
-      "version": "7.1.4",
-      "resolved": "https://registry.npmjs.org/minimal-slp-wallet/-/minimal-slp-wallet-7.1.4.tgz",
-      "integrity": "sha512-oHPDu+dUyAT8YOyKvb6JGZYIoalXAEHvcAUby7OgL3D/5R+cR21FTjpqpp7BJp+NFcGRANohnLAqpP2vt6tgFA==",
+      "version": "7.1.5",
+      "resolved": "https://registry.npmjs.org/minimal-slp-wallet/-/minimal-slp-wallet-7.1.5.tgz",
+      "integrity": "sha512-dROdawFZJZLvyTRndJi987S+z0cOG9k6coyyTAfkaaQftP+UayjUyjKeQlJVrKAPgIzxhk6EoZKD6AtoGjwQrw==",
       "license": "MIT",
       "dependencies": {
         "@chris.troutner/retry-queue": "1.0.11",
-        "@psf/bch-js": "7.1.11",
+        "@psf/bch-js": "7.1.14",
         "bch-consumer": "1.6.2",
         "bch-donation": "1.1.2",
         "crypto-js": "4.0.0"

package.json

@@ -15,12 +15,12 @@
   "license": "MIT",
   "description": "REST API proxy to Bitcoin Cash infrastructure",
   "dependencies": {
-    "@psf/bch-js": "7.1.11",
+    "@psf/bch-js": "7.1.14",
     "axios": "1.7.7",
     "cors": "2.8.5",
     "dotenv": "16.3.1",
     "express": "5.1.0",
-    "minimal-slp-wallet": "7.1.4",
+    "minimal-slp-wallet": "7.1.5",
     "psffpp": "1.2.1",
     "slp-token-media": "1.2.10",
     "winston": "3.11.0",

production/data/.gitkeep

@@ -0,0 +1 @@
+

production/docker/.env-example

@@ -9,7 +9,7 @@ RPC_PASSWORD=password
 FULCRUM_API=http://172.17.0.1:3001/v1
 
 # SLP Indexer
-SLP_INDEXER_API=http://172.17.0.1:5010
+SLP_INDEXER_API=http://172.17.0.1:5020
 
 # REST API URL for wallet operations
 LOCAL_RESTURL=http://172.17.0.1:5942/v6

production/docker/docker-compose.yml

@@ -17,4 +17,6 @@ services:
       volumes:
         #- ./start-rest2nostr.sh:/home/safeuser/REST2NOSTR/start-rest2nostr.sh
         - ./.env:/home/safeuser/.env
+        - ../data:/home/safeuser/psf-bch-api/production/data
+        - ../data/logs:/home/safeuser/psf-bch-api/logs
       restart: always

src/config/env/common.js

@@ -47,6 +47,11 @@ export default {
   // Server port
   port: parseInt(process.env.PORT, 10) || 5942,
 
+  // HTTP server connection lifecycle configuration.
+  serverKeepAliveTimeoutMs: Number(process.env.SERVER_KEEPALIVE_TIMEOUT_MS || 3000),
+  serverHeadersTimeoutMs: Number(process.env.SERVER_HEADERS_TIMEOUT_MS || 65000),
+  serverRequestTimeoutMs: Number(process.env.SERVER_REQUEST_TIMEOUT_MS || 120000),
+
   // Environment
   env: process.env.NODE_ENV || 'development',
 

src/controllers/rest-api/slp/controller.js

@@ -208,7 +208,14 @@ class SlpRESTController {
   }
 
   handleError (err, res) {
-    wlogger.error('Error in SlpRESTController:', err)
+    const isCommonMissingTxError =
+      err?.status === 404 &&
+      typeof err?.message === 'string' &&
+      err.message.includes('Key not found in database')
+
+    if (!isCommonMissingTxError) {
+      wlogger.error('Error in SlpRESTController:', err)
+    }
 
     const status = err.status || 500
     const message = err.message || 'Internal server error'

src/use-cases/fulcrum-use-cases.js

@@ -146,7 +146,7 @@ class FulcrumUseCases {
       if (response.transactions && Array.isArray(response.transactions)) {
         // Use bearer token from request if provided, otherwise use the default bchjs instance
         let bchjsInstance = this.bchjs
-        
+
         // console.log('getTransactionsBulk() bearerToken: ', bearerToken)
         if (bearerToken) {
           // Create a temporary bchjs instance with the bearer token from the request

src/use-cases/slp-use-cases.js

@@ -98,7 +98,14 @@ class SlpUseCases {
     try {
       return await this.slpIndexer.post('slp/tx/', { txid })
     } catch (err) {
-      wlogger.error('Error in SlpUseCases.getTxid()', err)
+      const isCommonMissingTxError =
+        err?.status === 404 &&
+        typeof err?.message === 'string' &&
+        err.message.includes('Key not found in database')
+
+      if (!isCommonMissingTxError) {
+        wlogger.error('Error in SlpUseCases.getTxid()', err)
+      }
       throw err
     }
   }