search

firebase / firebase-tools

The Firebase Command Line Tools
MIT License
4.01k stars 925 forks source link

--inspect-functions not listening on port 9229 #6709

Open j1mmie opened 7 months ago

j1mmie commented 7 months ago

[REQUIRED] Environment info

firebase-tools: 13.0.3 node: v18.19.0

Platform: macOS 14.2.1 (23C71)

[REQUIRED] Test case

firebase emulators:start --only functions --inspect-functions --debug

[REQUIRED] Steps to reproduce

firebase emulators:start --only functions --inspect-functions --debug

[REQUIRED] Expected behavior

Firebase emulator should open port 9229 for connections and allow debuggers (like VSCode) to connect.

[REQUIRED] Actual behavior

> firebase emulators:start --only functions --inspect-functions --debug
[2024-01-23T20:17:43.874Z] > command requires scopes: ["email","openid","https://www.googleapis.com/auth/cloudplatformprojects.readonly","https://www.googleapis.com/auth/firebase","https://www.googleapis.com/auth/cloud-platform"]
[2024-01-23T20:17:43.875Z] > authorizing via signed-in user (REDACTED)
i  emulators: Starting emulators: functions {"metadata":{"emulator":{"name":"hub"},"message":"Starting emulators: functions"}}
[2024-01-23T20:17:44.763Z] [logging] Logging Emulator only supports listening on one address (127.0.0.1). Not listening on ::1
[2024-01-23T20:17:44.763Z] assigned listening specs for emulators {"user":{"hub":[{"address":"127.0.0.1","family":"IPv4","port":4400},{"address":"::1","family":"IPv6","port":4400}],"ui":[{"address":"127.0.0.1","family":"IPv4","port":4000},{"address":"::1","family":"IPv6","port":4000}],"logging":[{"address":"127.0.0.1","family":"IPv4","port":4500}]},"metadata":{"message":"assigned listening specs for emulators"}}
[2024-01-23T20:17:44.770Z] [hub] writing locator at /var/folders/31/dstnktz109vcsd3y_h0mrncm0000gn/T/REDACTED.json
[2024-01-23T20:17:45.220Z] [eventarc] Eventarc Emulator only supports listening on one address (127.0.0.1). Not listening on ::1
[2024-01-23T20:17:45.220Z] late-assigned ports for functions and eventarc emulators {"user":{"hub":[{"address":"127.0.0.1","family":"IPv4","port":4400},{"address":"::1","family":"IPv6","port":4400}],"ui":[{"address":"127.0.0.1","family":"IPv4","port":4000},{"address":"::1","family":"IPv6","port":4000}],"logging":[{"address":"127.0.0.1","family":"IPv4","port":4500}],"functions":[{"address":"0.0.0.0","family":"IPv4","port":5001}],"eventarc":[{"address":"127.0.0.1","family":"IPv4","port":9299}]},"metadata":{"message":"late-assigned ports for functions and eventarc emulators"}}
⚠  functions: You are running the Functions emulator in debug mode (port=9229). This means that functions will execute in sequence rather than in parallel. {"metadata":{"emulator":{"name":"functions"},"message":"You are running the Functions emulator in debug mode (port=9229). This means that functions will execute in sequence rather than in parallel."}}
⚠  functions: The following emulators are not running, calls to these services from the Functions emulator will affect production: auth, firestore, database, hosting, pubsub, storage {"metadata":{"emulator":{"name":"functions"},"message":"The following emulators are not running, calls to these services from the Functions emulator will affect production: \u001b[1mauth, firestore, database, hosting, pubsub, storage\u001b[22m"}}
[2024-01-23T20:17:45.223Z] defaultcredentials: writing to file /Users/REDACTED/.config/firebase/REDACTED.json
[2024-01-23T20:17:45.225Z] Setting GAC to /Users/REDACTED/.config/firebase/REDACTED.json {"metadata":{"emulator":{"name":"functions"},"message":"Setting GAC to /Users/REDACTED/.config/firebase/REDACTED.json"}}
[2024-01-23T20:17:45.227Z] >>> [apiv2][query] GET https://firebase.googleapis.com/v1beta1/projects/REDACTED/adminSdkConfig [none]
[2024-01-23T20:17:45.699Z] <<< [apiv2][status] GET https://firebase.googleapis.com/v1beta1/projects/REDACTED/adminSdkConfig 200
[2024-01-23T20:17:45.700Z] <<< [apiv2][body] GET https://firebase.googleapis.com/v1beta1/projects/REDACTED/adminSdkConfig {"projectId":"REDACTED","storageBucket":"REDACTED.appspot.com","locationId":"us-central"}
[2024-01-23T20:17:45.738Z] Ignoring unsupported arg: auto_download {"metadata":{"emulator":{"name":"ui"},"message":"Ignoring unsupported arg: auto_download"}}
[2024-01-23T20:17:45.738Z] Ignoring unsupported arg: port {"metadata":{"emulator":{"name":"ui"},"message":"Ignoring unsupported arg: port"}}
[2024-01-23T20:17:45.738Z] Starting Emulator UI with command {"binary":"node","args":["/Users/REDACTED/.cache/firebase/emulators/ui-v1.11.7/server/server.js"],"optionalArgs":[],"joinArgs":false} {"metadata":{"emulator":{"name":"ui"},"message":"Starting Emulator UI with command {\"binary\":\"node\",\"args\":[\"/Users/REDACTED/.cache/firebase/emulators/ui-v1.11.7/server/server.js\"],\"optionalArgs\":[],\"joinArgs\":false}"}}
i  ui: Emulator UI logging to ui-debug.log {"metadata":{"emulator":{"name":"ui"},"message":"Emulator UI logging to \u001b[1mui-debug.log\u001b[22m"}}
[2024-01-23T20:17:45.965Z] Web / API server started at 127.0.0.1:4000
 {"metadata":{"emulator":{"name":"ui"},"message":"Web / API server started at 127.0.0.1:4000\n"}}
[2024-01-23T20:17:45.966Z] Web / API server started at ::1:4000
 {"metadata":{"emulator":{"name":"ui"},"message":"Web / API server started at ::1:4000\n"}}
i  functions: Watching "/Users/REDACTED/functions" for Cloud Functions... {"metadata":{"emulator":{"name":"functions"},"message":"Watching \"REDACTED/dist/apps/functions\" for Cloud Functions..."}}
[2024-01-23T20:17:46.015Z] Validating nodejs source
[2024-01-23T20:17:46.619Z] > [functions] package.json contents: {
  "name": "functions",
  "description": "Firebase Functions package, auto generated by @simondotm/nx-firebase",
  "scripts": {
    "lint": "nx lint functions",
    "build": "nx build functions",
    "deploy": "firebase deploy --only functions --config firebase.json",
    "logs": "firebase functions:log"
  },
  "engines": {
    "node": "18"
  },
  "dependencies": {
    "firebase": "9.19.1",
    "firebase-admin": "11.11.1",
    "firebase-functions": "4.6.0"
  },
  "devDependencies": {},
  "private": true,
  "main": "./src/index.js",
  "type": "commonjs"
}
[2024-01-23T20:17:46.620Z] Building nodejs source
[2024-01-23T20:17:46.621Z] Failed to find version of module node: reached end of search path /Users/REDACTED/dist/apps/functions/node_modules
✔  functions: Using node@18 from host.
[2024-01-23T20:17:46.623Z] Could not find functions.yaml. Must use http discovery
[2024-01-23T20:17:46.632Z] Found firebase-functions binary at '/Users/REDACTED/node_modules/.bin/firebase-functions'
Serving at port 8322

[2024-01-23T20:17:47.433Z] Got response from /__/functions.yaml {"endpoints":{"temp":{"platform":"gcfv1","availableMemoryMb":null,"timeoutSeconds":null,"minInstances":null,"maxInstances":null,"ingressSettings":null,"serviceAccountEmail":null,"vpc":null,"secretEnvironmentVariables":[],"httpsTrigger":{},"entryPoint":"temp"}},"specVersion":"v1alpha1","requiredAPIs":[{"api":"cloudscheduler.googleapis.com","reason":"Needed for scheduled functions."}]}
✔  functions: Loaded functions definitions from source: test. {"metadata":{"emulator":{"name":"functions"},"message":"Loaded functions definitions from source: test."}}
✔  functions[us-central1-test]: http function initialized (http://127.0.0.1:5001/REDACTED/us-central1/test). {"metadata":{"emulator":{"name":"functions"},"message":"\u001b[1mhttp\u001b[22m function initialized (http://127.0.0.1:5001/REDACTED/us-central1/test)."}}
⚠  To enable function inspection, please run "npm i node@18.0.0 --save-dev" in your functions directory {"metadata":{"emulator":{"name":"functions"},"message":"To enable function inspection, please run \"npm i node@18.0.0 --save-dev\" in your functions directory"}}
[2024-01-23T20:17:47.500Z] [worker-pool] addWorker(~shared~) {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] addWorker(~shared~)"}}
[2024-01-23T20:17:47.501Z] [worker-pool] Adding worker with key ~free~, total=1 {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] Adding worker with key ~free~, total=1"}}
[2024-01-23T20:17:48.174Z] [runtime-status] [61149] Resolved module firebase-admin {"declared":true,"installed":true,"version":"11.11.1","resolution":"/Users/REDACTED/node_modules/firebase-admin/lib/index.js"} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Resolved module firebase-admin {\"declared\":true,\"installed\":true,\"version\":\"11.11.1\",\"resolution\":\"/Users/REDACTED/node_modules/firebase-admin/lib/index.js\"}"}}
[2024-01-23T20:17:48.175Z] [runtime-status] [61149] Resolved module firebase-functions {"declared":true,"installed":true,"version":"4.6.0","resolution":"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js"} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Resolved module firebase-functions {\"declared\":true,\"installed\":true,\"version\":\"4.6.0\",\"resolution\":\"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js\"}"}}
[2024-01-23T20:17:48.175Z] [runtime-status] [61149] Outgoing network have been stubbed. [{"name":"http","status":"mocked"},{"name":"http","status":"mocked"},{"name":"https","status":"mocked"},{"name":"https","status":"mocked"},{"name":"net","status":"mocked"}] {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Outgoing network have been stubbed. [{\"name\":\"http\",\"status\":\"mocked\"},{\"name\":\"http\",\"status\":\"mocked\"},{\"name\":\"https\",\"status\":\"mocked\"},{\"name\":\"https\",\"status\":\"mocked\"},{\"name\":\"net\",\"status\":\"mocked\"}]"}}
[2024-01-23T20:17:48.176Z] [runtime-status] [61149] Resolved module firebase-functions {"declared":true,"installed":true,"version":"4.6.0","resolution":"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js"} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Resolved module firebase-functions {\"declared\":true,\"installed\":true,\"version\":\"4.6.0\",\"resolution\":\"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js\"}"}}
[2024-01-23T20:17:48.297Z] [runtime-status] [61149] Checked functions.config() {"config":{}} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Checked functions.config() {\"config\":{}}"}}
[2024-01-23T20:17:48.297Z] [runtime-status] [61149] firebase-functions has been stubbed. {"functionsResolution":{"declared":true,"installed":true,"version":"4.6.0","resolution":"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js"}} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] firebase-functions has been stubbed. {\"functionsResolution\":{\"declared\":true,\"installed\":true,\"version\":\"4.6.0\",\"resolution\":\"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js\"}}"}}
[2024-01-23T20:17:48.297Z] [runtime-status] [61149] Resolved module firebase-functions {"declared":true,"installed":true,"version":"4.6.0","resolution":"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js"} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Resolved module firebase-functions {\"declared\":true,\"installed\":true,\"version\":\"4.6.0\",\"resolution\":\"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js\"}"}}
[2024-01-23T20:17:48.298Z] [runtime-status] [61149] Resolved module firebase-admin {"declared":true,"installed":true,"version":"11.11.1","resolution":"/Users/REDACTED/node_modules/firebase-admin/lib/index.js"} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Resolved module firebase-admin {\"declared\":true,\"installed\":true,\"version\":\"11.11.1\",\"resolution\":\"/Users/REDACTED/node_modules/firebase-admin/lib/index.js\"}"}}
[2024-01-23T20:17:48.299Z] [runtime-status] [61149] Resolved module firebase-functions {"declared":true,"installed":true,"version":"4.6.0","resolution":"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js"} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Resolved module firebase-functions {\"declared\":true,\"installed\":true,\"version\":\"4.6.0\",\"resolution\":\"/Users/REDACTED/node_modules/firebase-functions/lib/v1/index.js\"}"}}
[2024-01-23T20:17:48.299Z] [runtime-status] [61149] firebase-admin has been stubbed. {"adminResolution":{"declared":true,"installed":true,"version":"11.11.1","resolution":"/Users/REDACTED/node_modules/firebase-admin/lib/index.js"}} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] firebase-admin has been stubbed. {\"adminResolution\":{\"declared\":true,\"installed\":true,\"version\":\"11.11.1\",\"resolution\":\"/Users/REDACTED/node_modules/firebase-admin/lib/index.js\"}}"}}
[2024-01-23T20:17:48.542Z] [runtime-status] [61149] Functions runtime initialized. {"cwd":"/Users/REDACTED/dist/apps/functions","node_version":"18.5.0"} {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Functions runtime initialized. {\"cwd\":\"/Users/REDACTED/dist/apps/functions\",\"node_version\":\"18.5.0\"}"}}
[2024-01-23T20:17:48.542Z] [runtime-status] [61149] Listening to port: /var/folders/31/dstnktz109vcsd3y_h0mrncm0000gn/T/fire_emu_09eccfd4af2f208e.sock {"metadata":{"emulator":{"name":"functions"},"message":"[runtime-status] [61149] Listening to port: /var/folders/31/dstnktz109vcsd3y_h0mrncm0000gn/T/fire_emu_09eccfd4af2f208e.sock"}}
[2024-01-23T20:17:48.623Z] [worker-~free~-12d0cb13-d8d5-4088-a6fe-1b3742975a9a]: IDLE {"metadata":{"emulator":{"name":"functions"},"message":"[worker-~free~-12d0cb13-d8d5-4088-a6fe-1b3742975a9a]: IDLE"}}

┌─────────────────────────────────────────────────────────────┐
│ ✔  All emulators ready! It is now safe to connect your app. │
│ i  View Emulator UI at http://127.0.0.1:4000/               │
└─────────────────────────────────────────────────────────────┘

┌───────────┬──────────────┬─────────────────────────────────┐
│ Emulator  │ Host:Port    │ View in Emulator UI             │
├───────────┼──────────────┼─────────────────────────────────┤
│ Functions │ 0.0.0.0:5001 │ http://127.0.0.1:4000/functions │
└───────────┴──────────────┴─────────────────────────────────┘
  Emulator Hub running at 127.0.0.1:4400
  Other reserved ports: 4500

Issues? Report them at https://github.com/firebase/firebase-tools/issues and attach the *-debug.log files.

Connecting via VSCode with the following launch.json configuration fails. The "connecting" panel shows for a few seconds then disappears without any error message.

{
  "name": "ATTACH functions:start",
  "type": "node",
  "request": "attach",
  "cwd": "${workspaceRoot}",
  "port": 9229,
  "resolveSourceMapLocations": [
    "${workspaceFolder}/**",
   "!**/node_modules/**",
   "!node:internal/**"
  ]
}

Telnet to port 9229 fails:

> telnet localhost 9229
Trying ::1...
telnet: connect to address ::1: Connection refused
Trying 127.0.0.1...
telnet: connect to address 127.0.0.1: Connection refused
telnet: Unable to connect to remote host

lsof (on macOS) shows no open sockets on port 9229:

> lsof -ti tcp:9229
# no output
> lsof -ti udp:9229
# no output
# To verify lsof is working, here's what I get for another server on port 3000:
> lsof -ti tcp:3000
5061
j1mmie commented 7 months ago

Update: Found a workaround

I had previously installed firebase-tools via the provided curl snippet (curl -sL firebase.tools | bash). I uninstalled that copy of firebase-tools (rm -fr /usr/local/bin/firebase) and reinstalled via NPM (npm install -g firebase-tools) and things are working again.

I'll leave this issue open and let the firebase team decide whether it's a bug in the curl install process, or maybe just an outlier. Thanks all

aalej commented 7 months ago

Hey @j1mmie, thanks for the detailed report and for sharing your observations. I was able to reproduce this, and as you mentioned, it does seem like the issue is only reproducible when firebase-tools is downloaded via curl -sL firebase.tools | bash. Installing it via NPM works fine.

Let me try to bring someone from our team to take a look into this.

joehan commented 7 months ago

Hey @j1mmie, glad that you found a workaround. Installs through firebase.tools do some dark magic in order to bundle node/npm alongside firebase-tools, which can cause some weirdness for parts of the codebase that call node directly. The functions emulator happens to do that, so I'm not shocked that it behaves incorrectly here.

I'll dig into this a bit to see if there is an easy fix - however, I'm hoping to replace that dark magic using single executable applications (https://nodejs.org/api/single-executable-applications.html) at some point, which will hopefully make this bug obsolete.

j1mmie commented 7 months ago

Great to hear, I'm glad I reported it then, thanks all.