search

mozilla-services / syncserver

Run-Your-Own Firefox Sync Server
Mozilla Public License 2.0
1.87k stars 145 forks source link

Docker container not syncing with 2FA account #168

Closed andrewkdinh closed 4 years ago

andrewkdinh commented 5 years ago

After setting up Firefox sync server, I could not sync with it because I get the error Failed to fetch the cluster URL: Error: user is not verified

These are the steps I took:

  1. Set up Firefox sync server with Docker on Lubuntu following the instructions from the README:

    $ git clone https://github.com/mozilla-services/syncserver.git && cd syncserver
$ docker build -t syncserver:latest .
$ docker run --restart=unless-stopped --name=syncserver -d -v /opt/syncserver:/data -p 5000:5000 -e SYNCSERVER_PUBLIC_URL=http://firefox.domain.com -e SYNCSERVER_SECRET=53b1023a45a4446e15be9b6c0041724f9c2a354d -e SYNCSERVER_SQLURI=sqlite:////tmp/syncserver.db -e SYNCSERVER_BATCH_UPLOAD_ENABLED=true -e SYNCSERVER_FORCE_WSGI_ENVIRON=false -e PORT=5000 syncserver:latest
$ sudo chmod 1001:1001 /opt/syncserver

  2. Ran test from the README, which exited with

    Ran 60 tests in 147.371s
OK (skipped=6)

  3. Created Nginx reverse proxy on another machine:

    server {
server_name firefox.domain.com;
listen 443;
listen [::]:443;
<SSL certs here>
    location / {
    proxy_pass http://192.168.x.x:5000;
    proxy_set_header Host $http_host;
    proxy_set_header X-Forwarded-Proto $scheme;
    proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
    proxy_set_header X-Real-IP $remote_addr;
    proxy_redirect off;
    proxy_read_timeout 120;
    proxy_connect_timeout 10;
}
}

    I was able to access it from firefox.domain.com, where it said it works!

  4. In about:config, I changed identity.sync.tokenserver.uri to https://firefox.domain.com/token/1.0/sync/1.5

Every time I try to sync from Firefox on Ubuntu, I get this in about:sync-log: PrivateBin

I also tested it without the reverse proxy, and it still gave the same error.

Any help is appreciated. Thanks in advanced!

UPDATE: After signing out and going back in, I now get this error: PrivateBin.

rfk commented 5 years ago

This log line:

1554504488845 Services.Common.RESTRequest TRACE onStartRequest: GET https://firefox.domain.com/1.0/sync/1.5

Suggests that your value of identity.sync.tokenserver.uri may be incorrect, could you please check that it contains the expected /token/ prefix on the URL path?

andrewkdinh commented 5 years ago

Same error after changing the url for identity.sync.tokenserver.uri to https://firefox.domain.com/token/1.0/sync/1.5, closing Firefox, and signing back into Firefox.

First error log (before restarting Firefox): PrivateBin Fourth and final error log, which was similar to the second and third error logs: PrivateBin

rfk commented 5 years ago

Error: user is not verified

When signing in, did you receive an email from Firefox Accounts asking you to "confirm this signin" or similar? If so, did you successfully click through to confirm it?

As far as I can see, the above error message should only be thrown if the browser thinks that you haven't verified the sign-in. But on the other hand, the brower shouldn't even be trying to sync if it doesn't think you verified the sign-in, so I'm really not sure what's going on here.

One option to debug further, would be to try adding more debug logging on the server side. Unfortunately this tends to be hard to do when running under docker, but ideally, you could try to modify the code in these two locations to get more information about why the "invalid-credentials" error is being returned:

https://github.com/mozilla-services/tokenserver/blob/c18d33fbb5319e138dd47a68e040271c0a48c462/tokenserver/views.py#L174 https://github.com/mozilla-services/tokenserver/blob/c18d33fbb5319e138dd47a68e040271c0a48c462/tokenserver/views.py#L183

andrewkdinh commented 5 years ago

Currently, I have 2FA and the recovery code enabled for my account. I tried signing in with a recovery code, but it gave me the same error. I then tried disabling 2FA, but that just allowed me to login to my Firefox account with my email and password, without having to go through any other verification (recovery code, email, etc.).

I instead tried syncing with a brand new account in a new Firefox profile, and I was able to successfully sync (no about:sync-log errors). I believe there is something wrong with my default Firefox profile or my Firefox account 2FA. Do you have any solutions for this? I would be willing to sync my old account to the new account if necessary.

rfk commented 5 years ago

Ah, interesting. I haven't seen this error before, but it seems like it could be some bad interaction between the self-hosting setup and 2FA. One thing you could try if you're willing, would be to create a new Firefox Account and add 2FA on that, and then see if you get the same error as you did with your main account.

andrewkdinh commented 5 years ago

I tried again with the new account I had created earlier. I signed in with both 2FA and the backup recovery codes that appeared after setting up 2FA. but still received the same error user is not verified in about:sync-log. Unfortunately, even after disabling 2FA, Firefox does not start sending me sign-in verification emails again.

unixfox commented 5 years ago

I'm having the same issue: user is not verified when running Firefox sync on Docker and logging in with an account that have 2FA enabled and even after disabling 2FA on my Firefox account. I can see in my webserver logs that I get a bunch of 401 HTTP error when trying to logging in:

[07/Jun/2019:14:19:41 +0000] "GET /token/1.0/sync/1.5 HTTP/2.0" 401 110 "-" "Mozilla/5.0 (Windows NT 10.0; rv:68.0) Gecko/20100101 Firefox/68.0" - 3ms
[07/Jun/2019:14:19:59 +0000] "GET /token/1.0/sync/1.5 HTTP/2.0" 401 110 "-" "Mozilla/5.0 (Windows NT 10.0; rv:68.0) Gecko/20100101 Firefox/68.0" - 3ms
rfk commented 5 years ago

I tried to reproduce this using my own Firefox Account with 2FA enabled, but it seemed to work OK for me and I was able to sync successfully with a local syncstorage server. I'm sorry but I'm really at a loss to think of what might possibly be going wrong here :-(

logging in with an account that have 2FA enabled and even after disabling 2FA on my Firefox account.

After disabling 2FA, did you try signing out and signing back in to Firefox? (be careful to double-check that the identity.sync.tokenserver.uri pref doesn't get reset to its default value when you sign out though)

captn3m0 commented 5 years ago

Facing the same.

tokenserver.uri: http://firesync.bb8.fun/token/1.0/sync/1.5

I already have 2 linux desktops syncing fine with this. This new device shows up everywhere else, and I got a green "you've successfully connected message" post login. Sync still fails with 


1564265501015   FirefoxAccounts DEBUG   service: c40f32fd2938f0b6
1564265501016   FirefoxAccounts DEBUG   is private browsing: false
1564265568969   FirefoxAccounts INFO    Polling device commands.
1564265568970   Sync.Service    DEBUG   User-Agent: Firefox/68.0.1 (Linux x86_64) FxSync/1.70.0.20190718161435.desktop
1564265568970   Sync.Service    INFO    Starting sync at 2019-07-28 03:42:48 in browser session FoNpkT5pfTqr
1564265568971   Sync.SyncScheduler  DEBUG   Clearing sync triggers and the global score.
1564265568972   Sync.Status INFO    Resetting Status.
1564265568972   Sync.Status DEBUG   Status.service: success.status_ok => success.status_ok
1564265568972   Sync.BrowserIDManager   INFO    Failed to fetch the cluster URL: Error: user is not verified(resource://services-sync/browserid_identity.js:544:13) JS Stack trace: _ensureValidToken@browserid_identity.js:544:13
_findCluster@browserid_identity.js:659:30
setCluster@browserid_identity.js:627:30
sync@enginesync.js:51:67
onNotify@service.js:1132:26
WrappedNotify@util.js:177:32
WrappedLock@util.js:133:27
_lockedSync@service.js:1164:8
sync/<@service.js:1118:18
WrappedCatch@util.js:103:27
sync@service.js:1119:7
1564265568972   Sync.ErrorHandler   ERROR   Sync encountered an error: Error: user is not verified(resource://services-sync/browserid_identity.js:544:13) JS Stack trace: _ensureValidToken@browserid_identity.js:544:13
_findCluster@browserid_identity.js:659:30
setCluster@browserid_identity.js:627:30
sync@enginesync.js:51:67
onNotify@service.js:1132:26
WrappedNotify@util.js:177:32
WrappedLock@util.js:133:27
_lockedSync@service.js:1164:8
sync/<@service.js:1118:18
WrappedCatch@util.js:103:27
sync@service.js:1119:7
1564265568973   Sync.SyncScheduler  DEBUG   Sync error count has exceeded 3; enforcing backoff.
1564265568973   Sync.SyncScheduler  DEBUG   Starting client-initiated backoff. Next sync in 9296874 ms.
1564265568973   Sync.SyncScheduler  DEBUG   Next sync in 9296874 ms. (why=client-backoff-schedule)
1564265568975   Sync.Service    DEBUG   Exception calling anonymous function: Error: user is not verified(resource://services-sync/browserid_identity.js:544:13) JS Stack trace: _ensureValidToken@browserid_identity.js:544:13
_findCluster@browserid_identity.js:659:30
setCluster@browserid_identity.js:627:30
sync@enginesync.js:51:67
onNotify@service.js:1132:26
WrappedNotify@util.js:177:32
WrappedLock@util.js:133:27
_lockedSync@service.js:1164:8
sync/<@service.js:1118:18
WrappedCatch@util.js:103:27
sync@service.js:1119:7

I also have 2FA enabled (was recently enabled so the previous 2 devices were added before that). I also have a "weird" iOS syncing device, which doesn't sync properly.

captn3m0 commented 5 years ago

Disabled 2FA on my account and restarted firefox, and it worked finally.

rfk commented 5 years ago

For folks who have been hitting this bug, have you by any chance changed the primary email address on your Firefox Account?

I don't have any theory as for what that might make a difference, but I'd seeing similar symptoms with a user in production who has both enabled 2FA and changed their primary email address, and I wonder if it might somehow be related to what you're seeing here.

captn3m0 commented 5 years ago

Yes, I did.

On 12-Aug-2019, at 08:02, Ryan Kelly notifications@github.com wrote:

For folks who have been hitting this bug, have you by any chance changed the primary email address on your Firefox Account?

I don't have any theory as for what that might make a difference, but I'd seeing similar symptoms with a user in production who has both enabled 2FA and changed their primary email address, and I wonder if it might somehow be related to what you're seeing here.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

rfk commented 5 years ago

Before or after setting up 2FA on your account?

captn3m0 commented 5 years ago

Logs from all emails I received from accounts@firefox.com (Skipping the New Sign-in emails).

Time Event
10/5/17, 2:41 AM Account Created (EMAIL A)
10/5/17, 2:43 AM Account Verified (EMAIL A)
2:33:24 AM (IST) Saturday, Apr 13, 2019 Account recovery key generated
2:33:55 AM (IST) Saturday, Apr 13, 2019 Verify secondary email Request (EMAIL B)
2:39:16 AM (IST) Saturday, Apr 13, 2019 Two-step authentication enabled
4/13/19, 9:22 PM Secondary email added (Verification link clicked)
7/28/19, 3:41 AM Primary email changed (from A to B)
7/28/19, 3:41 AM Primary email changed back (from B to A)
2:04:06 PM (IST) Thursday, Aug 1, 2019 Two-step authentication disabled (After discussion on this thread)

Timestamps are from the email content when the email contained it, otherwise timestamp of when I received the email. All timestamps in IST. Happy to provide A and B over a private channel(email in profile)

qnten commented 5 years ago

Having the same problem. Any updates on this? Don't know if that's a coincidence but the problem first occurred around the same time i tried to sync a ios device. Similiar to @captn3m0:

I also have 2FA enabled (was recently enabled so the previous 2 devices were added before that). I also have a "weird" iOS syncing device, which doesn't sync properly.

fractalf commented 5 years ago

I'm not using 2FA, but have similar issue. Just tried to install the syncserver behind a nxing proxy and though things seems to be set up correctly I get auth errors when logging into my mozilla account (yes I restarted firefox etc after changing about:config)

nginx log ->

[08/Nov/2019:21:28:27 +0000] "GET /token/1.0/sync/1.5 HTTP/2.0" 401 110 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:71.0) Gecko/20100101 Firefox/71.0"

about:config ->

image

about:sync-log (some of the errors) ->

...
1573248506937   Sync.Status DEBUG   Status.service: success.status_ok => error.login.failed
...
1573248506938   Sync.Status DEBUG   Status.service: error.login.failed => success.status_ok
...
1573248507235   Services.Common.TokenServerClient   INFO    Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
...
1573248507575   Sync.BrowserIDManager   ERROR   Authentication error in _fetchTokenForUser: {"details":{"now":"2019-11-08T21:28:27.575Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\": \"invalid-credentials\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Unauthorized\"}]}","response_headers":{"server":"nginx/1.17.4","date":"Fri, 08 Nov 2019 21:28:27 GMT","content-type":"application/json; charset=UTF-8","content-length":"110","x-weave-timestamp":"1573248507.57","x-timestamp":"1573248507","strict-transport-security":"max-age=31536000","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
...

My cert seems to be ok etc (using lets encrypt from this repo) image

I'll happily do some more debugging if you guys can't reproduce, just let me know

knulpi commented 4 years ago

I'm not using 2FA, but have similar issue. Just tried to install the syncserver behind a nxing proxy and though things seems to be set up correctly I get auth errors when logging into my mozilla account (yes I restarted firefox etc after changing about:config)

In my case, the error appeared with the same setup. But it was solved with following the exact instructions for running the syncserver behind a web-server: https://mozilla-services.readthedocs.io/en/latest/howtos/run-sync-1.5.html#running-behind-a-web-server

rfk commented 4 years ago

"message":"Authentication failed.","cause":"invalid-credentials"

FWIW, this "invalid-credentials" error usually indicates some sort of config problem, as suggested by @juliusberger above. It might mean for example that your server thinks its public-facing URL is "http://example.com" but the client thinks it should be "https://example.com" or something like that. You can try setting SYNCSERVER_FORCE_WSGI_ENVIRON to true and see if that helps.

Unfortunately I'm still no closer to understanding what's happening with the 2FA situation here :-(

andrewkdinh commented 4 years ago

"message":"Authentication failed.","cause":"invalid-credentials"

FWIW, this "invalid-credentials" error usually indicates some sort of config problem, as suggested by @juliusberger above. It might mean for example that your server thinks its public-facing URL is "http://example.com" but the client thinks it should be "https://example.com" or something like that. You can try setting SYNCSERVER_FORCE_WSGI_ENVIRON to true and see if that helps.

Unfortunately I'm still no closer to understanding what's happening with the 2FA situation here :-(

Doing both of this fixed my problem. My Firefox syncserver now works with my account (with 2FA still enabled). Thanks!