ianperrin / MMM-Strava

A MagicMirror Module for your Strava data.
https://forum.magicmirror.builders/topic/457/mmm-strava?_=1616840157932
MIT License
49 stars 15 forks source link

Client ID Not Authorized #66

Closed BerkSmash1984 closed 1 year ago

BerkSmash1984 commented 2 years ago

When submitting a new issue, please supply the following information:

Platform (Hardware/OS): Raspberry Pi 4B, 4GB Raspbian GNU/Linux 10 (buster)

Node Version: v16.15.0

MagicMirror Version: v2.19.0

Description: I am getting client id not authorized, despite having my client ID and client secret correct (from Strava API page). I also have the whitelist setup correctly and can access my MM from my local browser (the MM itself is on a RPI4). I receive the link within the magic mirror and am redirected to the authorization page on Strava, but after clicking authorize and restarting MM, I am still getting the same client ID not authorized. In looking in electron, I do so a ERR_HTTP_HEADERS_SENT error message. Also, I do not see the tokens.json being generated in the MMM-Strava folder after clicking authorize for the Strava auth redirect site Any help would be greatly appreciated. Screenshots below, along with details from Electron for the ERR_HTTP_HEADERS_SENT error

image

image

image

image

[03.05.2022 10:13.13.537] [ERROR] Whoops! There was an uncaught exception… [03.05.2022 10:13.13.538] [ERROR] Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client at new NodeError (node:internal/errors:371:5) at ServerResponse.setHeader (node:_http_outgoing:576:11) at ServerResponse.header (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:776:10) at ServerResponse.location (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:893:15) at ServerResponse.redirect (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:931:18) at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:185:10 at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:451:5 at node:fs:2122:7 at FSReqCallback.oncomplete (node:fs:188:23) { code: ‘ERR_HTTP_HEADERS_SENT’

Steps to Reproduce: See screenshots above

Expected Results: functional Strava module in magic mirror

Actual Results: Strava-MMM still stating client ID not authorized when running Magic Mirror

Configuration: What does the used config.js file look like? Don't forget to remove any sensitive information!

Additional Notes: in the MM forums, another poster (sdetweil stated the following:

so, this error is typically caused by some code doing two sends for an incoming request

the module sets up a little server to receive and does a redirect response…

but this could be an async problem start sending one response, continue while it runs and then fall into another send… oops…

I only made a cursory look at the code. i have done similar things in some of my coding here and on other platforms.

I don’t ‘see’ it, but there is a library in there too

this says it is handling a callback on request complete,

line 185 is in the handling of the token auth . but the stravea lib is calling back into the function (function (err, payload, limits) at line 176 so the node_helper called strava, who called us back at the function on line 185 ( (err, data) => { (err, data) => { ) which does a redirect… WHILE the strava request to get the auth token handler is still active…

strava.oauth.getToken(authCode, function (err, payload, limits) {
            if (err) {
                console.error(err);
                res.redirect(`/${self.name}/auth/?error=${err}`);
                return;
            }
            // Store tokens
            self.saveToken(clientId, payload.body, (err, data) => {    // line 185
                // redirect route
                res.redirect(`/${self.name}/auth/?status=success`);
            });
        });

line 451, is in the end of the saveFile() function, supposedly to save the tokens.json

saveToken: function (clientId, token, cb) { var self = this; this.readTokens(); // No token for clientId - delete existing if (clientId in this.tokens && !token) { delete this.tokens[clientId]; } // No clientId in tokens - create stub if (!(clientId in this.tokens) && token) { this.tokens[clientId] = {}; } // Add token for client if (token) { this.tokens[clientId].token = token; } // Save tokens to file var json = JSON.stringify(this.tokens, null, 2); fs.writeFile(this.tokensFile, json, "utf8", function (error) { if (error && cb) { cb(error); } if (cb) { cb(null, self.tokens); // line 451 --- this calls back into the ( (err, data) =>) function } })

at FSReqCallback.oncomplete (node:fs:188:23) {

ianperrin commented 2 years ago

Hi @BerkSmash1984

Thanks for the detailed report.

Could you try again, but this time set the debug option for the module to true and then capture the output from the logs on the Pi and also from the console in the electron browser?

That might help provide a little more info

Thanks

On 3 May 2022, at 17:38, BerkSmash1984 @.***> wrote:

 When submitting a new issue, please supply the following information:

Platform (Hardware/OS): Raspberry Pi 4B, 4GB Raspbian GNU/Linux 10 (buster)

Node Version: v16.15.0

MagicMirror Version: v2.19.0

Description: I am getting client id not authorized, despite having my client ID and client secret correct (from Strava API page). I also have the whitelist setup correctly and can access my MM from my local browser (the MM itself is on a RPI4). I receive the link within the magic mirror and am redirected to the authorization page on Strava, but after clicking authorize and restarting MM, I am still getting the same client ID not authorized. In looking in electron, I do so a ERR_HTTP_HEADERS_SENT error message. Also, I do not see the tokens.json being generated in the MMM-Strava folder after clicking authorize for the Strava auth redirect site Any help would be greatly appreciated. Screenshots below, along with details from Electron for the ERR_HTTP_HEADERS_SENT error

[03.05.2022 10:13.13.537] [ERROR] Whoops! There was an uncaught exception… [03.05.2022 10:13.13.538] [ERROR] Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client at new NodeError (node:internal/errors:371:5) at ServerResponse.setHeader (node:_http_outgoing:576:11) at ServerResponse.header (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:776:10) at ServerResponse.location (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:893:15) at ServerResponse.redirect (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:931:18) at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:185:10 at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:451:5 at node:fs:2122:7 at FSReqCallback.oncomplete (node:fs:188:23) { code: ‘ERR_HTTP_HEADERS_SENT’

Steps to Reproduce: See screenshots above

Expected Results: functional Strava module in magic mirror

Actual Results: Strava-MMM still stating client ID not authorized when running Magic Mirror

Configuration: What does the used config.js file look like? Don't forget to remove any sensitive information!

Additional Notes: in the MM forums, another poster (sdetweil stated the following:

so, this error is typically caused by some code doing two sends for an incoming request

the module sets up a little server to receive and does a redirect response…

but this could be an async problem start sending one response, continue while it runs and then fall into another send… oops…

I only made a cursory look at the code. i have done similar things in some of my coding here and on other platforms.

I don’t ‘see’ it, but there is a library in there too

this says it is handling a callback on request complete,

line 185 is in the handling of the token auth . but the stravea lib is calling back into the function (function (err, payload, limits) at line 176 so the node_helper called strava, who called us back at the function on line 185 ( (err, data) => { (err, data) => { ) which does a redirect… WHILE the strava request to get the auth token handler is still active…

strava.oauth.getToken(authCode, function (err, payload, limits) { if (err) { console.error(err); res.redirect(/${self.name}/auth/?error=${err}); return; } // Store tokens self.saveToken(clientId, payload.body, (err, data) => { // line 185 // redirect route res.redirect(/${self.name}/auth/?status=success); }); }); line 451, is in the end of the saveFile() function, supposedly to save the tokens.json

saveToken: function (clientId, token, cb) { var self = this; this.readTokens(); // No token for clientId - delete existing if (clientId in this.tokens && !token) { delete this.tokens[clientId]; } // No clientId in tokens - create stub if (!(clientId in this.tokens) && token) { this.tokens[clientId] = {}; } // Add token for client if (token) { this.tokens[clientId].token = token; } // Save tokens to file var json = JSON.stringify(this.tokens, null, 2); fs.writeFile(this.tokensFile, json, "utf8", function (error) { if (error && cb) { cb(error); } if (cb) { cb(null, self.tokens); // line 451 --- this calls back into the ( (err, data) =>) function } })

at FSReqCallback.oncomplete (node:fs:188:23) {

— Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you are subscribed to this thread.

BerkSmash1984 commented 2 years ago

@ianperrin thank you for the response. I set the debug: true in the config.js for the MMM-Strava module: image

As far as output in Electron, it looks the same as it does when I click authorize on the Strava authorization redirect page, as it did before setting the debug value

image

[04.05.2022 06:51.14.462] [ERROR] Whoops! There was an uncaught exception... [04.05.2022 06:51.14.478] [ERROR] Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client at new NodeError (node:internal/errors:371:5) at ServerResponse.setHeader (node:_http_outgoing:576:11) at ServerResponse.header (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:776:10) at ServerResponse.location (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:893:15) at ServerResponse.redirect (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:931:18) at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:185:10 at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:451:5 at node:fs:2122:7 at FSReqCallback.oncomplete (node:fs:188:23) { code: 'ERR_HTTP_HEADERS_SENT' } [04.05.2022 06:51.14.483] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection? [04.05.2022 06:51.14.484] [ERROR] If you think this really is an issue, please open an issue on GitHub: https://github.com/MichMich/MagicMirror/issues

For the logs on the pi, are you referring to the logs located in /home/jberk1984/.npm/_logs? If so, here is the last generated log file and it does not have anything significant in it:

0 verbose cli /usr/bin/node /usr/bin/npm 1 info using npm@8.8.0 2 info using node@v16.15.0 3 timing npm:load:whichnode Completed in 0ms 4 timing config:load:defaults Completed in 4ms 5 timing config:load:file:/usr/lib/node_modules/npm/npmrc Completed in 2ms 6 timing config:load:builtin Completed in 2ms 7 timing config:load:cli Completed in 4ms 8 timing config:load:env Completed in 1ms 9 timing config:load:file:/home/jberk1984/MagicMirror/.npmrc Completed in 0ms 10 timing config:load:project Completed in 9ms 11 timing config:load:file:/home/jberk1984/.npmrc Completed in 3ms 12 timing config:load:user Completed in 3ms 13 timing config:load:file:/usr/etc/npmrc Completed in 0ms 14 timing config:load:global Completed in 1ms 15 timing config:load:validate Completed in 1ms 16 timing config:load:credentials Completed in 2ms 17 timing config:load:setEnvs Completed in 2ms 18 timing config:load Completed in 30ms 19 timing npm:load:configload Completed in 30ms 20 timing npm:load:mkdirpcache Completed in 2ms 21 timing npm:load:mkdirplogs Completed in 1ms 22 verbose title npm start 23 verbose argv "start" 24 timing npm:load:setTitle Completed in 3ms 25 timing config:load:flatten Completed in 7ms 26 timing npm:load:display Completed in 12ms 27 verbose logfile logs-max:10 dir:/home/jberk1984/.npm/_logs 28 verbose logfile /home/jberk1984/.npm/_logs/2022-05-04T10_52_49_874Z-debug-0.log 29 timing npm:load:logFile Completed in 15ms 30 timing npm:load:timers Completed in 1ms 31 timing npm:load:configScope Completed in 0ms 32 timing npm:load Completed in 67ms 33 silly logfile start cleaning logs, removing 1 files 34 silly logfile done cleaning log files

Here is how my API app looks in case there is anything wrong with the setup:

image

ianperrin commented 2 years ago

Thanks @BerkSmash1984

Can you add the debug option inside the config options e.g.

config: {
    debug: true,
    client_id: “”,
    client_secret: “”
}

Then get the output from the electron console when the error occurs and the MagicMirror logs (pm2?)

Ian

On 4 May 2022, at 11:57, BerkSmash1984 @.***> wrote:  @ianperrin thank you for the response. I set the debug: true in the config.js for the MMM-Strava module:

As far as output in Electron, it looks the same as it does when I click authorize on the Strava authorization redirect page, as it did before setting the debug value

[04.05.2022 06:51.14.462] [ERROR] Whoops! There was an uncaught exception... [04.05.2022 06:51.14.478] [ERROR] Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client at new NodeError (node:internal/errors:371:5) at ServerResponse.setHeader (node:_http_outgoing:576:11) at ServerResponse.header (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:776:10) at ServerResponse.location (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:893:15) at ServerResponse.redirect (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:931:18) at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:185:10 at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:451:5 at node:fs:2122:7 at FSReqCallback.oncomplete (node:fs:188:23) { code: 'ERR_HTTP_HEADERS_SENT' } [04.05.2022 06:51.14.483] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection? [04.05.2022 06:51.14.484] [ERROR] If you think this really is an issue, please open an issue on GitHub: https://github.com/MichMich/MagicMirror/issues

For the logs on the pi, are you referring to the logs located in /home/jberk1984/.npm/_logs? If so, here is the last generated log file and it does not have anything significant in it:

0 verbose cli /usr/bin/node /usr/bin/npm 1 info using @. 2 info using @. 3 timing npm:load:whichnode Completed in 0ms 4 timing config:load:defaults Completed in 4ms 5 timing config:load:file:/usr/lib/node_modules/npm/npmrc Completed in 2ms 6 timing config:load:builtin Completed in 2ms 7 timing config:load:cli Completed in 4ms 8 timing config:load:env Completed in 1ms 9 timing config:load:file:/home/jberk1984/MagicMirror/.npmrc Completed in 0ms 10 timing config:load:project Completed in 9ms 11 timing config:load:file:/home/jberk1984/.npmrc Completed in 3ms 12 timing config:load:user Completed in 3ms 13 timing config:load:file:/usr/etc/npmrc Completed in 0ms 14 timing config:load:global Completed in 1ms 15 timing config:load:validate Completed in 1ms 16 timing config:load:credentials Completed in 2ms 17 timing config:load:setEnvs Completed in 2ms 18 timing config:load Completed in 30ms 19 timing npm:load:configload Completed in 30ms 20 timing npm:load:mkdirpcache Completed in 2ms 21 timing npm:load:mkdirplogs Completed in 1ms 22 verbose title npm start 23 verbose argv "start" 24 timing npm:load:setTitle Completed in 3ms 25 timing config:load:flatten Completed in 7ms 26 timing npm:load:display Completed in 12ms 27 verbose logfile logs-max:10 dir:/home/jberk1984/.npm/_logs 28 verbose logfile /home/jberk1984/.npm/_logs/2022-05-04T10_52_49_874Z-debug-0.log 29 timing npm:load:logFile Completed in 15ms 30 timing npm:load:timers Completed in 1ms 31 timing npm:load:configScope Completed in 0ms 32 timing npm:load Completed in 67ms 33 silly logfile start cleaning logs, removing 1 files 34 silly logfile done cleaning log files

Here is how my API app looks in case there is anything wrong with the setup:

— Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you were mentioned.

BerkSmash1984 commented 2 years ago

@ianperrin here you go:

[04.05.2022 12:22.27.075] [LOG]   MMM-Strava: "Received notification: SET_CONFIG"
[04.05.2022 12:22.27.077] [LOG]   MMM-Strava: "Unauthorised client id for module_9_MMM-Strava"
[04.05.2022 12:22.27.081] [LOG]   MMM-Strava: "Getting data for module_9_MMM-Strava"
[04.05.2022 12:22.27.083] [LOG]   MMM-Strava: "Access token not found for module_9_MMM-Strava"
[04.05.2022 12:22.27.084] [LOG]   Use existing newsfetcher for url: http://rss.cnn.com/rss/cnn_topstories.rss
[04.05.2022 12:22.27.085] [INFO]  Newsfeed-Fetcher: Broadcasting 47 items.
[04.05.2022 12:22.27.090] [LOG]   Use existing newsfetcher for url: https://www.technologyreview.com/feed/
[04.05.2022 12:22.27.091] [INFO]  Newsfeed-Fetcher: Broadcasting 10 items.
[04.05.2022 12:22.27.096] [LOG]   Use existing newsfetcher for url: http://feeds.arstechnica.com/arstechnica/technology-lab
[04.05.2022 12:22.27.097] [INFO]  Newsfeed-Fetcher: Broadcasting 20 items.
[04.05.2022 12:22.27.100] [LOG]   Use existing newsfetcher for url: https://holycitysinner.com/feed/
[04.05.2022 12:22.27.102] [INFO]  Newsfeed-Fetcher: Broadcasting 10 items.
[04.05.2022 12:22.27.108] [LOG]   Use existing newsfetcher for url: https://rpilocator.com/feed.rss
[04.05.2022 12:22.27.109] [INFO]  Newsfeed-Fetcher: Broadcasting 20 items.
[04.05.2022 12:22.27.113] [INFO]  Notification: GET_PIHOLE Payload: [object Object]
[04.05.2022 12:22.28.065] [INFO]  Newsfeed-Fetcher: Broadcasting 20 items.
[04.05.2022 12:22.28.201] [INFO]  Newsfeed-Fetcher: Broadcasting 20 items.
[04.05.2022 12:22.28.396] [INFO]  Calendar-Fetcher: Broadcasting 4 events.
[04.05.2022 12:22.28.481] [INFO]  Newsfeed-Fetcher: Broadcasting 47 items.
[04.05.2022 12:22.28.514] [INFO]  Newsfeed-Fetcher: Broadcasting 10 items.
[04.05.2022 12:22.28.594] [INFO]  Calendar-Fetcher: Broadcasting 0 events.
[04.05.2022 12:22.32.163] [INFO]  Notification: GET_PIHOLE Payload: [object Object]
[04.05.2022 12:22.32.467] [INFO]  Newsfeed-Fetcher: Broadcasting 10 items.
[04.05.2022 12:22.34.491] [LOG]   MMM-Strava: "Requesting access for 83285"
[04.05.2022 12:22.39.047] [LOG]   MMM-Strava: "Getting token for 83285"
[04.05.2022 12:22.39.351] [ERROR] Whoops! There was an uncaught exception...
[04.05.2022 12:22.39.357] [ERROR] Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client
    at new NodeError (node:internal/errors:371:5)
    at ServerResponse.setHeader (node:_http_outgoing:576:11)
    at ServerResponse.header (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:776:10)
    at ServerResponse.location (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:893:15)
    at ServerResponse.redirect (/home/jberk1984/MagicMirror/node_modules/express/lib/response.js:931:18)
    at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:185:10
    at /home/jberk1984/MagicMirror/modules/MMM-Strava/node_helper.js:451:5
    at node:fs:2122:7
    at FSReqCallback.oncomplete (node:fs:188:23) {
  code: 'ERR_HTTP_HEADERS_SENT'
}
[04.05.2022 12:22.39.359] [ERROR] MagicMirror² will not quit, but it might be a good idea to check why this happened. Maybe no internet connection?
[04.05.2022 12:22.39.359] [ERROR] If you think this really is an issue, please open an issue on GitHub: https://github.com/MichMich/MagicMirror/issues

Is it possible to pre-stage the access token it is expecting here? [04.05.2022 12:22.27.083] [LOG] MMM-Strava: "Access token not found for module_9_MMM-Strava"

I do not have pm2 installed and only see logs in the /home/jberk1984/.npm/logs directory, which are not very helpful

image

0 verbose cli /usr/bin/node /usr/bin/npm
1 info using npm@8.8.0
2 info using node@v16.15.0
3 timing npm:load:whichnode Completed in 1ms
4 timing config:load:defaults Completed in 3ms
5 timing config:load:file:/usr/lib/node_modules/npm/npmrc Completed in 2ms
6 timing config:load:builtin Completed in 2ms
7 timing config:load:cli Completed in 4ms
8 timing config:load:env Completed in 1ms
9 timing config:load:file:/home/jberk1984/MagicMirror/.npmrc Completed in 0ms
10 timing config:load:project Completed in 8ms
11 timing config:load:file:/home/jberk1984/.npmrc Completed in 2ms
12 timing config:load:user Completed in 2ms
13 timing config:load:file:/usr/etc/npmrc Completed in 0ms
14 timing config:load:global Completed in 0ms
15 timing config:load:validate Completed in 1ms
16 timing config:load:credentials Completed in 2ms
17 timing config:load:setEnvs Completed in 3ms
18 timing config:load Completed in 28ms
19 timing npm:load:configload Completed in 29ms
20 timing npm:load:mkdirpcache Completed in 2ms
21 timing npm:load:mkdirplogs Completed in 0ms
22 verbose title npm start
23 verbose argv "start"
24 timing npm:load:setTitle Completed in 2ms
25 timing config:load:flatten Completed in 7ms
26 timing npm:load:display Completed in 12ms
27 verbose logfile logs-max:10 dir:/home/jberk1984/.npm/_logs
28 verbose logfile /home/jberk1984/.npm/_logs/2022-05-04T16_21_47_995Z-debug-0.log
29 timing npm:load:logFile Completed in 16ms
30 timing npm:load:timers Completed in 0ms
31 timing npm:load:configScope Completed in 0ms
32 timing npm:load Completed in 66ms
33 silly logfile start cleaning logs, removing 1 files
34 silly logfile done cleaning log files

Is there somewhere else I should be looking? Really appreciate your help here

BerkSmash1984 commented 2 years ago

@ianperrin I just wanted to let you know I was able to resolve this issue this AM. Apparently, when completing the authorization process and in generating the token file in the MMM-Strava directory, there was an issue with the permissions. Upon setting the applicable permissions via chmod, I am not able to get the module to function on my MM. Thanks for your responses while I was troubleshooting

ianperrin commented 2 years ago

Great to hear you got it fixed. Might be worth adding some error traps there so we can see similar errors in future 😉

On 9 May 2022, at 14:50, BerkSmash1984 @.***> wrote:

 @ianperrin I just wanted to let you know I was able to resolve this issue this AM. Apparently, when completing the authorization process and in generating the token file in the MMM-Strava directory, there was an issue with the permissions. Upon setting the applicable permissions via chmod, I am not able to get the module to function on my MM. Thanks for your responses while I was troubleshooting

— Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you were mentioned.