Closed brianmhunt closed 1 year ago
Try changing params
to data
like this...
export ping = functions.https.onCall(async (data, context) => {
if (!context.auth) { throw new Error("Where's the auth?") }
console.log("Have auth", context.auth)
})
@chinesehemp I may misunderstand, but renaming an unused argument isn't going to help (because a.) the name is irrelevant and b.) in any case it isn't used). Perhaps you could please clarify what you were thinking might help?
@brianmhunt I had a similar issue with the emulator and https.onCall functions where I only included context as the arg. So inside the function, I was also finding context.auth was coming back as null. After I included data in the args with context, somehow the function was able to return context.auth again. Not sure exactly why it was happening, but it worked. I thought maybe it might work for you too. I'm using firebase-cli 11.16.0 FYI.
Here's the most trivial repro:
export const ping2 = functions.https.onCall((a, b) => console.log({a, b}))
... and call with
> firebaseFunctions.httpsCallable('ping2')()
The results are:
> {
> a: null,
> b: {
> rawRequest: IncomingMessage {
> _readableState: [ReadableState],
> _events: [Object: null prototype],
> _eventsCount: 1,
> _maxListeners: undefined,
> socket: [Socket],
> httpVersionMajor: 1,
> httpVersionMinor: 1,
> httpVersion: '1.1',
> complete: true,
> rawHeaders: [Array],
> rawTrailers: [],
> aborted: false,
> upgrade: false,
> url: '/',
> method: 'POST',
> statusCode: null,
> statusMessage: null,
> client: [Socket],
> _consuming: true,
> _dumped: false,
> next: [Function: next],
> baseUrl: '',
> originalUrl: '/',
> _parsedUrl: [Url],
> params: [Object],
> query: {},
> res: [ServerResponse],
> body: [Object],
> _body: true,
> length: undefined,
> rawBody: <Buffer 7b 22 64 61 74 61 22 3a 6e 75 6c 6c 7d>,
> route: [Route],
> [Symbol(kCapture)]: false,
> [Symbol(kHeaders)]: [Object],
> [Symbol(kHeadersCount)]: 40,
> [Symbol(kTrailers)]: null,
> [Symbol(kTrailersCount)]: 0,
> [Symbol(RequestTimeout)]: undefined
> }
> }
> }
Version / DevTools:
> firebase.SDK_VERSION
'9.14.0'
$ npm list |grep -i firebase
functions@ /workspaces/MinuteBox/services/firebase/functions
├── firebase-admin@11.2.1
├── firebase-functions@4.0.2
├── firebase-tools@11.16.0
I'll try to create a repo to demonstrate this but it's a bit odd that everyone using the library isn't encountering this.
Interestingly, even after downgrading all the packages the problem continues to exhibit i.e. reverting the following updates:
Noting that when I add this debugging info:
It says:
TOKENS STASTUS:::⭐️ { tokenStatus: { app: 'MISSING', auth: 'MISSING' } }
What's particularly peculiar is that the Authorziation
header is clearly being sent:
but in firebase-functions/lib/common/providers/https.js@checkAuthToken:
we don't see that header:
> REQ AUTH ⭐️ undefined {
> host: 'localhost:7902',
> connection: 'keep-alive',
> 'content-length': '13',
> pragma: 'no-cache',
> 'cache-control': 'no-cache',
> 'sec-ch-ua': '"Not?A_Brand";v="8", "Chromium";v="108", "Google Chrome";v="108"',
> 'content-type': 'application/json',
> 'sec-ch-ua-mobile': '?0',
> 'user-agent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36',
> 'sec-ch-ua-platform': '"macOS"',
> accept: '*/*',
> origin: 'http://localhost:7100',
> 'sec-fetch-site': 'same-site',
> 'sec-fetch-mode': 'cors',
> 'sec-fetch-dest': 'empty',
> referer: 'http://localhost:7100/',
> 'accept-encoding': 'gzip, deflate, br',
> 'accept-language': 'en-CA,en;q=0.9,fr-CA;q=0.8,fr;q=0.7,en-US;q=0.6',
> 'x-original-auth': 'Bearer eyJhbGciOiJub25lIiwidHlwIjoiSldUIn0.eyJhY2NvdW50cyI6eyJlbXUtMDAxIjp7ImFkbWluIjp0cnVlLCJiaWxsaW5nQWRtaW4iOmZhbHNlLCJ0ZWFtRmlsdGVyS2V5cyI6W10sInVzZXIiOnRydWV9fSwib3RwIjpmYWxzZSwiZW1haWwiOiJhZG1pbkBleGFtcGxlLmNvbSIsImVtYWlsX3ZlcmlmaWVkIjpmYWxzZSwiYXV0aF90aW1lIjoxNjY4MjY2ODczLCJ1c2VyX2lkIjoidWlkLS1hZG1pbkBleGFtcGxlLmNvbSIsImZpcmViYXNlIjp7ImlkZW50aXRpZXMiOnsiZW1haWwiOlsiYWRtaW5AZXhhbXBsZS5jb20iXX0sInNpZ25faW5fcHJvdmlkZXIiOiJwYXNzd29yZCJ9LCJpYXQiOjE2NjgyNjY4ODQsImV4cCI6MTY2ODI3MDQ4NCwiYXVkIjoiZGVtby1taW51dGVib3gtZW11bGF0aW9uIiwiaXNzIjoiaHR0cHM6Ly9zZWN1cmV0b2tlbi5nb29nbGUuY29tL2RlbW8tbWludXRlYm94LWVtdWxhdGlvbiIsInN1YiI6InVpZC0tYWRtaW5AZXhhbXBsZS5jb20ifQ.',
> 'x-callable-context-auth': '%7B%22uid%22%3A%22uid--admin%40example.com%22%2C%22token%22%3A%7B%22accounts%22%3A%7B%22emu-001%22%3A%7B%22admin%22%3Atrue%2C%22billingAdmin%22%3Afalse%2C%22teamFilterKeys%22%3A%5B%5D%2C%22user%22%3Atrue%7D%7D%2C%22otp%22%3Afalse%2C%22email%22%3A%22admin%40example.com%22%2C%22email_verified%22%3Afalse%2C%22auth_time%22%3A1668266873%2C%22user_id%22%3A%22uid--admin%40example.com%22%2C%22firebase%22%3A%7B%22identities%22%3A%7B%22email%22%3A%5B%22admin%40example.com%22%5D%7D%2C%22sign_in_provider%22%3A%22password%22%7D%2C%22iat%22%3A1668266884%2C%22exp%22%3A1668270484%2C%22aud%22%3A%22demo-minutebox-emulation%22%2C%22iss%22%3A%22https%3A%2F%2Fsecuretoken.google.com%2Fdemo-minutebox-emulation%22%2C%22sub%22%3A%22uid--admin%40example.com%22%2C%22uid%22%3A%22uid--admin%40example.com%22%7D%7D'
> }
... suggesting it's being scrubbed somewhere.
Possibly related: https://github.com/firebase/firebase-tools/issues/2910
It looks suspiciously like the problem is intertwined with cors/lib/index.js
, but I can't test it at the moment.
Noting that if I add logging at runFunction
in firebase-tools/lib/emulator/functionsEmulatorRuntime.ts
like this:
await runFunction(() => {
console.log(`⭐️ ⭐️ args `, args[0], args[1])
return trigger(args[0], args[1]);
});
I see logging that includes the Authorization Bearer token:
rawHeaders: [ ... 'Bearer eyJ...',
So the authorization header would seem to be removed between the start/end points on the stack trace:
> at /workspaces/repo/services/firebase/functions/dist/index.js:233025:19
> at /workspaces/repo/services/firebase/functions/dist/index.js:233016:21
> at cors2 (/workspaces/repo/services/firebase/functions/dist/index.js:232703:11)
> at /workspaces/repo/services/firebase/functions/dist/index.js:232735:21
> at originCallback (/workspaces/repo/services/firebase/functions/dist/index.js:232726:19)
> at /workspaces/repo/services/firebase/functions/dist/index.js:232730:17
> at optionsCallback (/workspaces/repo/services/firebase/functions/dist/index.js:232712:13)
> at corsMiddleware (/workspaces/repo/services/firebase/functions/dist/index.js:232716:11)
> at /workspaces/repo/services/firebase/functions/dist/index.js:233015:31
> at new Promise (<anonymous>)
> at /workspaces/repo/services/firebase/functions/dist/index.js:233013:16
> at /workspaces/repo/services/end-to-end-tests/node_modules/firebase-tools/lib/emulator/functionsEmulatorRuntime.js:531:16
> at runFunction (/workspaces/repo/services/end-to-end-tests/node_modules/firebase-tools/lib/emulator/functionsEmulatorRuntime.js:504:15)
> at runHTTPS (/workspaces/repo/services/end-to-end-tests/node_modules/firebase-tools/lib/emulator/functionsEmulatorRuntime.js:529:11)
> at /workspaces/repo/services/end-to-end-tests/node_modules/firebase-tools/lib/emulator/functionsEmulatorRuntime.js:695:27
> at Layer.handle [as handle_request] (/workspaces/repo/services/end-to-end-tests/node_modules/firebase-tools/node_modules/express/lib/router/layer.js:95:5)
cors
Modifying function cors
like this:
function cors2(options5, req, res, next) {
console.log(`⭐️ REQ:::`, req.headers)
I observe that there's no Authentication header, however there is an x-original-auth
Purely on instinct I suspect whatever is stripping the header is probably also adding this non-standard header. I don't see any reference to it in the code though.
corsMiddleware
Tracing back to corsMiddleware and adding this:
240603 return function corsMiddleware(req, res, next) {
240604 console.log(`⭐️ ⭐️ corsMiddleware`, req.headers)
240605 optionsCallback(req, function(err2, options5) {
we still see no sign of the Authorization header.
onCallHandler
... back to the onCallHandler
240897 function onCallHandler(options5, handler) {
240898 const wrapped = wrapOnCallHandler(options5, handler);
240899 return (req, res) => {
240900 console.log(`⭐️ ⭐️ onCallHandler`, req.headers)
240901 return new Promise((resolve) => {
We still see no Auth header
Just for certainty I checked that the Authorization header is being passed:
runHTTPS
Checking the runHTTPS
argument in firebase-tools/lib/emulator/functionsEmulatorRuntime.js
:
693 case "http":
694 console.log(`⭐️ runHTTPS...`, req.headers)
695 await runHTTPS(trigger, [req, res]);
... still no sign of the header:
app.all /*
... and similarly when moving the logging to app.all:
667 app.all(`/*`, async (req, res) => {
668 console.log(`⭐️ app.all /* :::`, req.headers)
669 try {
670 new types_1.EmulatorLog("INFO", "runtime-status", `Beginning execution of "${FUNCTION_TARGET_NAME}"`).log();
If we add logging to express.js we see:
130 if (layer.method && layer.method !== method) {
131 console.log(`⭐️ layer::: [${req.method}]`, req.path, req.header('Authorization'))
132 return next(err);
133 }
134
135 if (err) {
136 layer.handle_error(err, req, res, next);
137 } else {
138 console.log(`⭐️ handling:::`, req.path, req.header('Authorization'))
139 layer.handle_request(req, res, next);
140 }
We see the calls contain the Authorization
(abbreviated for brevity):
⭐️ layer::: [POST] /demo-minutebox-emulation/us-central1/userFunctions-ping Bearer eyJhbGciOiJub25lIiwidHlwIjoiSldUIn0.... ⭐️ handling:: [POST]: /demo-minutebox-emulation/us-central1/userFunctions-ping Bearer eyJhbGciOiJub25lIiwidHlwIjoiSldUIn0... ⭐️ handling:: [POST]: /demo-minutebox-emulation/us-central1/userFunctions-ping Bearer eyJhbGciOiJub25lIiwidHlwIjoiSldUIn0...
So the Authorization
is present in Express, but not present at functionsEmulatorRuntime.js
here:
667 app.all(`/*`, async (req, res) => {
OPTIONS
call and it had no Authorization header (as expected).wrapCallableHandler
I suspected that this function was involved in removing the headers but the following yielded no logging at all.
296 function wrapCallableHandler(handler) {
297 const newHandler = (data, context) => {
298 console.log(`⭐️ wrapCallableHandler`, context.rawRequest.get('Authorization'))
299 if (context.rawRequest) {
300 const authContext = context.rawRequest.header(functionsEmulatorShared_1.HttpConstants.CALLABLE_AUTH_HEADER);
301 if (authContext) {
302 logDebug("Callable functions auth override", {
303 key: functionsEmulatorShared_1.HttpConstants.CALLABLE_AUTH_HEADER,
304 value: authContext,
.... which is itself a bit surprising.
In the blame
I'm noting the commits over the past few months by @taeold @bkendall @colerogers -- leads me to believe that something got lost in the refactor. (Apologies for the tag/spam.)
There wasn't much that stood out but here's what I get when I trigger the function with firebase emulators:start --debug
[2022-11-15T20:41:13.556Z] [work-queue] {"queueLength":1,"workRunningCount":0}
[2022-11-15T20:41:13.558Z] [work-queue] {"queueLength":0,"workRunningCount":1}
[2022-11-15T20:41:13.560Z] Accepted request OPTIONS /demo-minutebox-emulation/us-central1/userFunctions-ping --> us-central1-userFunctions-ping
[2022-11-15T20:41:13.561Z] [functions] Runtime ready! Sending request! {"metadata":{"emulator":{"name":"functions"},"message":"[functions] Runtime ready! Sending request!"}}
[2022-11-15T20:41:13.562Z] [functions] Got req.url=/demo-minutebox-emulation/us-central1/userFunctions-ping, mapping to path=/ {"metadata":{"emulator":{"name":"functions"},"message":"[functions] Got req.url=/demo-minutebox-emulation/us-central1/userFunctions-ping, mapping to path=/"}}
i functions: Loaded environment variables from .env.local.
[2022-11-15T20:41:13.593Z] [worker-pool] addWorker(us-central1-userFunctions-ping) {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] addWorker(us-central1-userFunctions-ping)"}}
[2022-11-15T20:41:13.594Z] [worker-pool] Adding worker with key us-central1-userFunctions-ping, total=1 {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] Adding worker with key us-central1-userFunctions-ping, total=1"}}
[2022-11-15T20:41:16.350Z] [runtime-status] [22919] Resolved module firebase-admin {"declared":true,"installed":true,"version":"11.2.1","resolution":"/workspace/services/firebase/functions/node_modules/firebase-admin/lib/index.js"} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Resolved module firebase-admin {\"declared\":true,\"installed\":true,\"version\":\"11.2.1\",\"resolution\":\"/workspace/services/firebase/functions/node_modules/firebase-admin/lib/index.js\"}"}}
[2022-11-15T20:41:16.352Z] [runtime-status] [22919] Resolved module firebase-functions {"declared":true,"installed":true,"version":"4.0.2","resolution":"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js"} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Resolved module firebase-functions {\"declared\":true,\"installed\":true,\"version\":\"4.0.2\",\"resolution\":\"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js\"}"}}
[2022-11-15T20:41:16.352Z] [runtime-status] [22919] Found local functions config: /workspace/services/firebase/functions/.runtimeconfig.json {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Found local functions config: /workspace/services/firebase/functions/.runtimeconfig.json"}}
[2022-11-15T20:41:16.353Z] [runtime-status] [22919] 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"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] 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\"}]"}}
[2022-11-15T20:41:16.354Z] [runtime-status] [22919] Resolved module firebase-functions {"declared":true,"installed":true,"version":"4.0.2","resolution":"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js"} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Resolved module firebase-functions {\"declared\":true,\"installed\":true,\"version\":\"4.0.2\",\"resolution\":\"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js\"}"}}
[2022-11-15T20:41:16.793Z] [runtime-status] [22919] Checked functions.config() {"config":{"super":{"emails":"name@domain.com"},"hosting":{"host":"localhost:7100"}}} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Checked functions.config() {\"config\":{\"super\":{\"emails\":\"name@domain.com\"},\"hosting\":{\"host\":\"localhost:7100\"}}}"}}
[2022-11-15T20:41:16.793Z] [runtime-status] [22919] firebase-functions has been stubbed. {"functionsResolution":{"declared":true,"installed":true,"version":"4.0.2","resolution":"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js"}} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] firebase-functions has been stubbed. {\"functionsResolution\":{\"declared\":true,\"installed\":true,\"version\":\"4.0.2\",\"resolution\":\"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js\"}}"}}
[2022-11-15T20:41:16.794Z] [runtime-status] [22919] Resolved module firebase-functions {"declared":true,"installed":true,"version":"4.0.2","resolution":"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js"} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Resolved module firebase-functions {\"declared\":true,\"installed\":true,\"version\":\"4.0.2\",\"resolution\":\"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js\"}"}}
[2022-11-15T20:41:16.798Z] [runtime-status] [22919] Resolved module firebase-admin {"declared":true,"installed":true,"version":"11.2.1","resolution":"/workspace/services/firebase/functions/node_modules/firebase-admin/lib/index.js"} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Resolved module firebase-admin {\"declared\":true,\"installed\":true,\"version\":\"11.2.1\",\"resolution\":\"/workspace/services/firebase/functions/node_modules/firebase-admin/lib/index.js\"}"}}
[2022-11-15T20:41:16.802Z] [runtime-status] [22919] Resolved module firebase-functions {"declared":true,"installed":true,"version":"4.0.2","resolution":"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js"} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Resolved module firebase-functions {\"declared\":true,\"installed\":true,\"version\":\"4.0.2\",\"resolution\":\"/workspace/services/firebase/functions/node_modules/firebase-functions/lib/v1/index.js\"}"}}
[2022-11-15T20:41:16.802Z] [runtime-status] [22919] firebase-admin has been stubbed. {"adminResolution":{"declared":true,"installed":true,"version":"11.2.1","resolution":"/workspace/services/firebase/functions/node_modules/firebase-admin/lib/index.js"}} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] firebase-admin has been stubbed. {\"adminResolution\":{\"declared\":true,\"installed\":true,\"version\":\"11.2.1\",\"resolution\":\"/workspace/services/firebase/functions/node_modules/firebase-admin/lib/index.js\"}}"}}
[2022-11-15T20:41:17.410Z] [runtime-status] [22919] Functions runtime initialized. {"cwd":"/workspace/services/firebase/functions","node_version":"16.18.1"} {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Functions runtime initialized. {\"cwd\":\"/workspace/services/firebase/functions\",\"node_version\":\"16.18.1\"}"}}
> (node:22919) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. {"user":"(node:22919) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.","metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"\u001b[90m> \u001b[39m (node:22919) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead."}}
> (Use `node --trace-deprecation ...` to show where the warning was created) {"user":"(Use `node --trace-deprecation ...` to show where the warning was created)","metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"\u001b[90m> \u001b[39m (Use `node --trace-deprecation ...` to show where the warning was created)"}}
[2022-11-15T20:41:17.411Z] [runtime-status] [22919] Listening to port: /tmp/fire_emu_6ea42fec340bfe36.sock {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"[runtime-status] [22919] Listening to port: /tmp/fire_emu_6ea42fec340bfe36.sock"}}
[2022-11-15T20:41:17.436Z] [worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: IDLE {"metadata":{"emulator":{"name":"functions"},"message":"[worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: IDLE"}}
[2022-11-15T20:41:17.436Z] [worker-pool] submitRequest(triggerId=us-central1-userFunctions-ping) {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] submitRequest(triggerId=us-central1-userFunctions-ping)"}}
[2022-11-15T20:41:17.436Z] [worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: BUSY {"metadata":{"emulator":{"name":"functions"},"message":"[worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: BUSY"}}
i functions: Beginning execution of "userFunctions.ping" {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"Beginning execution of \"userFunctions.ping\""}}
[2022-11-15T20:41:17.439Z] [worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: IDLE {"metadata":{"emulator":{"name":"functions"},"message":"[worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: IDLE"}}
[2022-11-15T20:41:17.439Z] [work-queue] {"queueLength":0,"workRunningCount":0}
i functions: Finished "userFunctions.ping" in 0.632291ms {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"Finished \"userFunctions.ping\" in 0.632291ms"}}
[2022-11-15T20:41:17.441Z] [work-queue] {"queueLength":1,"workRunningCount":0}
[2022-11-15T20:41:17.441Z] [work-queue] {"queueLength":0,"workRunningCount":1}
[2022-11-15T20:41:17.441Z] Accepted request POST /demo-minutebox-emulation/us-central1/userFunctions-ping --> us-central1-userFunctions-ping
[2022-11-15T20:41:17.441Z] [functions] Runtime ready! Sending request! {"metadata":{"emulator":{"name":"functions"},"message":"[functions] Runtime ready! Sending request!"}}
[2022-11-15T20:41:17.442Z] [functions] Got req.url=/demo-minutebox-emulation/us-central1/userFunctions-ping, mapping to path=/ {"metadata":{"emulator":{"name":"functions"},"message":"[functions] Got req.url=/demo-minutebox-emulation/us-central1/userFunctions-ping, mapping to path=/"}}
[2022-11-15T20:41:17.442Z] [worker-pool] submitRequest(triggerId=us-central1-userFunctions-ping) {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] submitRequest(triggerId=us-central1-userFunctions-ping)"}}
[2022-11-15T20:41:17.442Z] [worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: BUSY {"metadata":{"emulator":{"name":"functions"},"message":"[worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: BUSY"}}
i functions: Beginning execution of "userFunctions.ping" {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"Beginning execution of \"userFunctions.ping\""}}
> {"verifications":{"app":"MISSING","auth":"MISSING"},"logging.googleapis.com/labels":{"firebase-log-type":"callable-request-verification"},"severity":"DEBUG","message":"Callable request verification passed"} {"user":{"verifications":{"app":"MISSING","auth":"MISSING"},"logging.googleapis.com/labels":{"firebase-log-type":"callable-request-verification"},"severity":"DEBUG","message":"Callable request verification passed"},"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"\u001b[90m> \u001b[39m {\"verifications\":{\"app\":\"MISSING\",\"auth\":\"MISSING\"},\"logging.googleapis.com/labels\":{\"firebase-log-type\":\"callable-request-verification\"},\"severity\":\"DEBUG\",\"message\":\"Callable request verification passed\"}"}}
> onCall | da992ba0-6525-11ed-863b-afde34df404d | 2022-11-15T20:41:17.402Z | 9b0f4372321aca0306bb0f478e5dd1c68f904a9f undefined {"user":"onCall | da992ba0-6525-11ed-863b-afde34df404d | 2022-11-15T20:41:17.402Z | 9b0f4372321aca0306bb0f478e5dd1c68f904a9f undefined","metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"\u001b[90m> \u001b[39m onCall | da992ba0-6525-11ed-863b-afde34df404d | 2022-11-15T20:41:17.402Z | 9b0f4372321aca0306bb0f478e5dd1c68f904a9f undefined"}}
[2022-11-15T20:41:17.466Z] [worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: IDLE {"metadata":{"emulator":{"name":"functions"},"message":"[worker-us-central1-userFunctions-ping-f27f8190-3ef1-486f-af4b-624b44c8f7d5]: IDLE"}}
[2022-11-15T20:41:17.466Z] [work-queue] {"queueLength":0,"workRunningCount":0}
i functions: Finished "userFunctions.ping" in 5.46325ms {"metadata":{"emulator":{"name":"functions"},"function":{"name":"us-central1-userFunctions-ping"},"extension":{},"message":"Finished \"userFunctions.ping\" in 5.46325ms"}}
@brianmhunt Thanks for a very detailed investigation.
I read over the issue, and while I don't yet have answer to why this is happening in your setup, I've got some clues that might help us:
1) Handling authorization header in the Functions Emulator involves a bit of unconventional dance. The FunctionsEmulator
will strip away the authorization header from the incoming request and stash it on x-original-auth
and in x-callable-context-auth
before forwarding the request to the FunctionsEmulatorRuntime
. Then, the FunctionsEmulatorRuntime
includes code that monkey patches the Firebase Function SDK's onCall
handler function to populate the context.auth
and req.header["authorization"]
from the custom headers I mentioned before before invoking the code you provided.
("That's sounds complicated!" you might say. We needed a way for the onCall handler to work with the request with unsigned authorization token to make it easy to generate fake auth tokens. Today the Admin and Functions SDK both natively support running in emulator environment, so in theory we don't need such a trick. But old code still remains).
Given that your screenshot includes x-original-auth
and x-callable-context-auth
but your context.auth
is still coming up empty handed, I wonder if the monkey patching code isn't working for some reason.
Can you share a little more about:
2) Instead of using the client JS SDK, I'm making a curl request to my callable function:
curl -X POST\
-H "Authorization: Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxMjM0NTY3ODkwIiwibmFtZSI6IkpvaG4gRG9lIiwiaWF0IjoxNTE2MjM5MDIyfQ.SflKxwRJSMeKKF2QT4fwpMeJf36POk6yJV_adQssw5c"\
-H "content-type: application/json"\
-d '{"data": {"n": 20}}'\
http://localhost:5001/REPLACE_ME_WITH_PATH_TO_CALLABLE
Can you reproduce the issue by doing something like this?
@taeold Thanks for the detailed description, this makes a lot of sense. I had essentially come to a conclusion about monkey patching (and legacy code). Your asking about the directories also seems insightful, since this seemingly isn't occurring for everyone I was looking for some distinguishing factor. We are in a monorepo so the directory structure is different from most, which might be that factor.
We have tried Node 16.14 and 16.18.1 (on Mac OSX, Ubuntu and Debian).
Here's the setup of the directories where relevant things are being installed (and I can post more/others if needed):
/
/package.json [1]
/services/end-to-end-tests/package.json [2]
/services/end-to-end-tests/emulator/firebase.json [3]
/services/firebase/functions/package.json [4]
MinuteBox on main via v16.14.0 on ☁️ brian@minutebox.com
❯ cat package.json| grep -i firebase
"@firebase/testing": "^0.20.11",
"firebase-tools": "^11.16",
"firebase": "^9.14.0",
"firebase-admin": "^11.2.1",
"firebase-functions": "^4.0.2",
MinuteBox/services/end-to-end-tests on main via v16.14.0 on ☁️ brian@minutebox.com
❯ cat package.json| grep -i firebase
"firebase-admin": "^11.2.1",
"firebase-tools": "=11.16.0",
(I pinned firebase-tools to 11.16.0 as part of this investigation)
services/end-to-end-tests/emulator on main on ☁️ brian@minutebox.com
❯ cat firebase.json
{
"emulators": {
"auth": {
"host": "0.0.0.0",
"port": 7901
},
"functions": {
"host": "0.0.0.0",
"port": 7902
},
"firestore": {
"host": "0.0.0.0",
"port": 7903
},
"pubsub": {
"host": "0.0.0.0",
"port": 7904
},
"storage": {
"host": "0.0.0.0",
"port": 7905
},
"eventarc": {
"port": 7906
},
"ui": {
"enabled": true,
"host": "0.0.0.0",
"port": 7900
},
"singleProjectMode": true
},
"storage": {
"rules": "storage.rules"
},
"functions": {
"source": "../../firebase/functions"
},
"firestore": {
"rules": "firestore.rules"
}
}
services/firebase/functions on main via v16.14.0 on ☁️ brian@minutebox.com
❯ cat package.json| grep -i firebase
"description": "Cloud Functions for Firebase",
"firebase-admin": "^11.2.1",
"firebase-functions": "^4.0.2",
$ URL=http://localhost:7902/demo-minutebox-emulation/us-central1/userFunctions-ping
$ curl -X POST -H "Authorization: Bearer eJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxMjM0NTY3ODkwIiwibmFtZSI6IkpvaG4gRG9lIiwiaWF0IjoxNTE2MjM5MDIyfQ.SflKxwRJSMeKKF2QT4fwpMeJf36POk6yJV_adQssw5c" -H "content-type: application/json" -d '{"data": {"n": 20}}' $URL
{"result":{"status":"ok","userID":"1234567890","userEmail":null,"now":"2022-11-18T12:43:08.621Z"}}
Where the trivial function is (roughly, pared down a bit here for brevity):
function ping ({ context, projectID }) {
return {
status: 'ok',
userID: context.auth ? context.auth.uid : null,
userEmail: context.auth ? context.auth.token.email : null,
now: new Date().toISOString(),
}
}
functions.runWith(runWith).region(REGION).https.onCall(async (params, context) => ping(context)
What's interesting is that we see the userID
. The email missing makes sense since it's not in the JWT. I hope this offers some insight.
I'm pretty ramped up on this problem, and it's quite important to us, so happy to dig deeper.
@taeold Sorry to ping, but just wanted to see if there's more information/investigation I might be able to provide on this issue, or if you have any hints as to what (monkey-patching) functions in the code might be worth looking at deeper. Thanks
@brianmhunt Sorry I dropped the ball on this issue.
CURL request/reply: What's interesting is that we see the userID. The email missing makes sense since it's not in the JWT. I hope this offers some insight.
Sadly this makes things even more confusing. So it looks like the auth context is available in the minimal example you've given, yet it is NOT available in the callable function that you are debugging.
I along with couple of other engineers in the team tried to reproduce the issue you are seeing here without success. If there is a minimal "project" setup that you can share to reproduce the issue, that'd help us investigate the issue tremendously.
Couple of shorts in the dark:
1) Is your callable function using the Functions SDK v1 or v2 API?
2) Is your emulated web application connected to the auth emulator?
Note that {"verifications":{"app":"MISSING","auth":"MISSING"}
is misleading in the Emulator world. It will ALWAYS claim to not have auth token, but that's because of the "hack" I mentioned in https://github.com/firebase/firebase-tools/issues/5210#issuecomment-1319348215. Functions Emulator bypasses the token verification process baked into the Functions SDK and will never see the auth token.
I'm running into the exact same problem on a very fresh project.
I did a fresh install last week, and now that I'm writing my first callable functions... no context.auth
. In fact, the only key on context
that's available to read is context.rawRequest
.
The repro is to
firebase/auth
implementation to your client, Here's my firebase.json
. Note that I'm using a monorepo with ./firebase
containing my Firebase rules, indexes, config, etc... and ./functions
containing the functions data.
{
"database": {
"rules": "database.rules.json"
},
"firestore": {
"rules": "firestore.rules",
"indexes": "firestore.indexes.json"
},
"functions": [
{
"source": "../functions",
"codebase": "default",
"ignore": ["node_modules", ".git", "firebase-debug.log", "firebase-debug.*.log"],
"predeploy": ["npm --prefix \"$RESOURCE_DIR\" run lint", "npm --prefix \"$RESOURCE_DIR\" run build"]
}
],
"hosting": {
"public": "public",
"ignore": ["firebase.json", "**/.*", "**/node_modules/**"]
},
"storage": {
"rules": "storage.rules"
},
"emulators": {
"auth": {
"port": 9099
},
"functions": {
"port": 5001
},
"firestore": {
"port": 8081
},
"database": {
"port": 9000
},
"hosting": {
"port": 5000
},
"storage": {
"port": 9199
},
"ui": {
"enabled": true,
"port": 4000
},
"singleProjectMode": true
},
"remoteconfig": {
"template": "remoteconfig.template.json"
}
}
Heres my package.json
for ./firebase
:
{
"name": "@jupiter/firebase",
"packageManager": "yarn@3.2.4",
"scripts": {
"dev": "dotenv firebase emulators:start --import --export-on-exit"
},
"devDependencies": {
"dotenv-cli": "^6.0.0",
"firebase-tools": "^11.18.0"
}
}
And here's the package.json
for ./functions
:
{
"name": "functions",
"scripts": {
"lint": "eslint --ext .js,.ts .",
"dev": "yarn build && chokidar \"./src/**/*.ts\" -c \"yarn build\"",
"build": "esbuild src/index.ts --bundle --sourcemap --platform=node --outfile=./lib/index.js",
"serve": "npm run build && firebase emulators:start --only functions",
"shell": "npm run build && firebase functions:shell",
"start": "npm run shell",
"deploy": "firebase deploy --only functions",
"logs": "firebase functions:log"
},
"engines": {
"node": "16"
},
"main": "lib/index.js",
"dependencies": {
"axios": "^1.2.1",
"firebase-admin": "^11.3.0",
"firebase-functions": "^4.1.1",
"googleapis": "^109.0.1",
"unique-names-generator": "^4.7.1"
},
"bundledDependencies": [
"api"
],
"devDependencies": {
"@typescript-eslint/eslint-plugin": "^5.46.1",
"@typescript-eslint/parser": "^5.46.1",
"chokidar-cli": "3.0.0",
"esbuild": "^0.16.4",
"eslint": "^8.29.0",
"eslint-config-google": "^0.14.0",
"eslint-plugin-import": "^2.26.0",
"firebase-functions-test": "^3.0.0",
"typescript": "^4.9.4"
},
"private": true
}
Note that I'm using esbuild
to bundle my functions. My monorepo setup requires dependencies from outside of ./functions
, and there was no reasonable way to get them into ./functions
without the bundler.
Some file structure for context...
@taeold Thanks, it is weird. On your questions:
The chief thing I think it might be smart to eliminate is whether the JWT being generated by the auth emulator is being rejected as unsigned, etc. How did you sign your sample JWT above [1]? jwt.io says if fails owing to a missing secret:
The JWT that I posted has algo: none
and type JWT, and it's considered valid. So it seems the auth emulator is producing something different from the sample you gave namely:
algo
type
These differences feel material and are in-band, otherwise I suspect we'll need to look at some sort of weird side-effect e.g. from peer headers.
Thanks @deltaepsilon for the repro instructions, that's excellent. It might be helpful to create a min-working-repro to expedite things, too (rather than the firebase devs having to block-and-copy everything).
Thanks for the help on this.
CC @LiutskoOlga
[1] eJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxMjM0NTY3ODkwIiwibmFtZSI6IkpvaG4gRG9lIiwiaWF0IjoxNTE2MjM5MDIyfQ.SflKxwRJSMeKKF2QT4fwpMeJf36POk6yJV_adQssw5c
I'm experiencing what is likely a related issue. After upgrading firebase tools (or firebase npm packages, not exactly sure when it started) the firestore emulator semi-randomly decides to reject all queries and updates from my app. Sometimes it works without issue, other times it just rejects everything as though there is no authenticated user even when there is. Rolling back to firebase-tools@10.9.2
fixes the problem, however that version is pretty old. At least the old version works well enough for now for my work to continue.
This really is a critical blocking bug, the newest versions of the emulators are unusable and I unfortunately wasted a lot of time figuring out that there was something wrong with the emulators and not my app.
Here's my minimal reproduction:
git clone git@github.com:deltaepsilon/firebase-emulator-bug.git
cd firebase-emulator-bug
yarn && yarn dev
Open localhost:3000, click the login button and try to run the callable function.
Thanks @deltaepsilon, that's great. @taeold ^^ hopefully this repro makes this straightforward to diagnose & remedy.
@taeold Just pinging on this, wondering if you've had a chance to try and repro it using the above github repo.
I'm currently using this abomination to work around it:
const xCallableContextAuth = context.rawRequest.headers['x-callable-context-auth'] as string ?? '';
const fakeAuth = decodeURIComponent(xCallableContextAuth);
const fakeAuthParsed = fakeAuth && JSON.parse(fakeAuth);
const userId = context.auth?.uid || fakeAuthParsed?.uid;
I seem to have run into a similar issue. I don't know if I can add much to a resolution, but for me the problem only occurs after switching to 2nd gen functions (import via firebase-functions/v2
).
Happy to share any other details that might be relevant
I created a workaround function that extracts auth off of the headers as necessary. It's working fine, although I wish they'd just patch their own code.
import { https } from 'firebase-functions';
export function getContextAuth(context: https.CallableContext) {
const xCallableContextAuth = (context.rawRequest.headers['x-callable-context-auth'] as string) ?? '';
const fakeAuth = decodeURIComponent(xCallableContextAuth);
const fakeAuthParsed = fakeAuth && JSON.parse(fakeAuth);
const userId = context.auth?.uid || fakeAuthParsed?.uid;
return { userId };
}
Hey folks, sorry that this issue fell under our radar. Using the sample repo that @deltaepsilon provided, I'm able to now reproduce this bug, and I'm going to dig into this a bit further. Thanks for your patience and sorry about the delay.
After looking into the setup of the sample repo, I think that the problem might be using a yarn/monorepo setup.
Basically, we have some code that tries to find the firebase-functions
sdk and overwrite the exported handler functions & creates the context object. If I use the provided sample, our code doesn't overwrite the sdk handlers. Since we (firebase) have been unsuccessful in reproducing this bug with a normal npm setup, I'm thinking this issue is caused from a using monorepo tooling. Is there anyone here that runs into this issue with a non-monorepo setup?
As it currently stands, firebase functions does not support monorepo (open issue for running firebase deploy
- #653 ). I'm wondering if issue for callable functions has always existed or is there a version of firebase-tools
that works with you folks?
I think yanking out our monkey-patching code would be the best course of action. But that would be a breaking change and would drop support for older versions of the SDK.
@brianmhunt @deltaepsilon
@colerogers Thanks for the investigation and reporting.
I'm wondering if issue for callable functions has always existed or is there a version of firebase-tools that works with you folks?
It was working fine for us in a monorepo on firebase-tools
11.6 but broke around 11.16. We tried to narrow the version but haven't had capacity yet.
I hope removing the monkey-patching is an option. I'd expect people who update firebase-tools to the latest also would be updating the SDK (but I've no evidence for this, only intuition :grin:).
The snippet I posted above is working great, so I'll stick with it for now. Hopefully other travelers can discover it and rescue themselves from auth hell.
We just released firebase-functions v4.2.1 that includes a patch our SDK for unpacking context.auth
from our internal headers. Upgrading to that version should fix this issue for monorepos. In the next firebase-tools
major (breaking) release, we'll remove all of our monkey-patching code. But since that repo contains code for other Firebase products, breaking change releases are a bigger thing. This should unblock everyone immediately who didn't use the above workaround. Thanks for all your patience!
I'll go ahead and mark this issue as closed
This appears to be working @colerogers , many thanks for the update and the fix.
@colerogers I just ran into the same issue using cloud functions gen 2. Switching to gen 1 fixed the problem.
Same here, @colerogers will v2 get a similar fix at some point?
Im running into the same issue after upgrading to v2 as well.
the same issue with v2 ;(
"firebase-functions": "4.4.1" firebase emulators: 12.7.0
Bumping, even today on April 18, 2024, I cannot access context.auth
in v2.
Hey folks, this is a pretty old closed issue and I don't usually monitor them. Usually it's best to open a new issue and link to a similar one as a reference, it's much easier for us to manage that way.
Given that, I just tried out v2 callable functions and I'm not able to reproduce the bug. Just so we are clear, you'd need to be authenticated for the auth
field to show up and have data. Also, the v2 version does not have a context
variable, instead auth
is just a field on the request parameter.
[REQUIRED] Environment info
firebase-tools:
Platform:
OS X 12.6
[REQUIRED] Test case
Run a trivial HTTPS callable function in the Functions Emulator. It does not have
context.auth
, as would be expected.[REQUIRED] Steps to reproduce
Listener:
Call with
functions.httpsCallable('ping')(),
[REQUIRED] Expected behavior
context.auth
have the expected credentials and output and emulator console show "Have auth" .[REQUIRED] Actual behavior
Emulator shows "Where's the auth?"
Related:
Packages / upgrade
This started occurring when we updated some packages, notably:
JWT Header
If we print the headers the authentication header has a proper (unsigned)
Bearer
token e.g. from jwt.ioDeploy vs emulator
The function works as expected when deployed, suggesting this is an emulator problem.