Unable to connect Google account after reboot on certain computer

Sync Issues
, ,
#1

Hi Everyone,

I have 1 PC and 2 Laptop.

I have connection fail on Google account only in PC when i shutdown or reboot. 2 Laptop is perfectly fine.

All of Computer is Windows 10 21H1.

image
image1298×1062 67.2 KB

Here is Error defails:

Mailspring Version: 1.9.1-30ef802f
Platform: win32
Account State: sync_error
Account Provider: gmail
IMAP Server: imap.gmail.com
SMTP Server: smtp.gmail.com
--------------------------------------------
15940 [2021-06-11 01:47:30.775] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
15940 [2021-06-11 01:47:31.692] [main] [info] [local-b4b06da2-e725] Running ChangeUnreadTask performLocal:
15940 [2021-06-11 01:47:31.695] [main] [info] [local-b4b06da2-e725] -- Succeeded. Changing status to `remote`
15940 [2021-06-11 01:47:32.335] [foreground] [info] Idle exited with code 0
15940 [2021-06-11 01:47:32.336] [foreground] [info] [local-b4b06da2-e725] Running ChangeUnreadTask performRemote:
15940 [2021-06-11 01:47:32.881] [foreground] [info] [local-b4b06da2-e725] -- Succeeded. Changing status to `complete`
15940 [2021-06-11 01:47:33.227] [foreground] [info] syncFolderChangesViaCondstore - [Gmail]/&yATMtLz0rQDVaA-: modseq 50077 to 50174, uidnext 1171 to 1171
15940 [2021-06-11 01:47:33.571] [foreground] [info] syncFolderChangesViaCondstore - Changes since HMODSEQ 50077: 1 changed, 0 vanished
15940 [2021-06-11 01:47:33.577] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
4236 [2021-06-11 01:55:15.850] [main] [info] Identity created at 1516741397 - using ID Schema 0
4236 [2021-06-11 01:55:15.852] [main] [info] ------------- Starting Sync (myaccount@gmail.com) ---------------
4236 [2021-06-11 01:55:15.986] [metadata] [info] Metadata delta stream starting...
4236 [2021-06-11 01:55:18.938] [background] [info] Fetching XOAuth2 access token (gmail) for 66b037d7
4236 [2021-06-11 01:55:19.226] [background] [info] Marking all folders as `busy`
4236 [2021-06-11 01:55:19.227] [background] [info] Syncing folder list...
4236 [2021-06-11 01:55:22.297] [background] [info] Syncing folder list...
4236 [2021-06-11 01:55:22.957] [background] [info] syncFolderUIDRange for [Gmail]/&yATMtLz0rQDVaA-, UIDs: 684 - 1171, Heavy: false
4236 [2021-06-11 01:55:23.723] [background] [info] - remote=400, local=400
4236 [2021-06-11 01:55:24.063] [background] [info] syncFolderUIDRange for [Gmail]/&1zTJwNG1-, UIDs: 1 - 113, Heavy: false
4236 [2021-06-11 01:55:24.753] [background] [info] - remote=110, local=110
4236 [2021-06-11 01:55:25.083] [background] [info] syncFolderUIDRange for [Gmail]/&wqTTONVo-, UIDs: 1 - 125, Heavy: false
4236 [2021-06-11 01:55:25.296] [foreground] [info] syncFolderChangesViaCondstore - [Gmail]/&yATMtLz0rQDVaA-: modseq 50174 to 50215, uidnext 1171 to 1171
4236 [2021-06-11 01:55:25.778] [background] [info] - remote=119, local=119
4236 [2021-06-11 01:55:25.780] [background] [info] Sync loop deleting unlinked messages with phase 2.
4236 [2021-06-11 01:55:25.780] [background] [info] Sync loop complete.
4236 [2021-06-11 01:55:25.958] [foreground] [info] syncFolderChangesViaCondstore - Changes since HMODSEQ 50174: 0 changed, 0 vanished
4236 [2021-06-11 01:55:25.963] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
4236 [2021-06-11 01:55:31.005] [metadataExpiration] [info] Scanning for expired metadata
4236 [2021-06-11 01:55:31.005] [metadataExpiration] [info] -- Will wake for next expiration in 7200sec

And here is mail sync log:

15940 [2021-06-11 01:45:46.220] [main] [info] Identity created at 1516741397 - using ID Schema 0
15940 [2021-06-11 01:45:46.222] [main] [info] ------------- Starting Sync (myaccount@gmail.com) ---------------
15940 [2021-06-11 01:45:48.039] [metadata] [info] Metadata delta stream starting...
15940 [2021-06-11 01:45:49.228] [background] [info] Fetching XOAuth2 access token (gmail) for 66b037d7
15940 [2021-06-11 01:45:49.491] [background] [info] Marking all folders as `busy`
15940 [2021-06-11 01:45:49.491] [background] [info] Syncing folder list...
15940 [2021-06-11 01:45:52.510] [background] [info] Syncing folder list...
15940 [2021-06-11 01:45:53.163] [background] [info] syncFolderUIDRange for [Gmail]/&yATMtLz0rQDVaA-, UIDs: 419 - 1169, Heavy: true
15940 [2021-06-11 01:45:55.230] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
15940 [2021-06-11 01:45:56.349] [background] [info] - remote=577, local=0
15940 [2021-06-11 01:45:58.281] [background] [info] syncFolderUIDRange for [Gmail]/&yATMtLz0rQDVaA-, UIDs: 419 - 418, Heavy: false
15940 [2021-06-11 01:45:58.739] [background] [info] - remote=577, local=577
15940 [2021-06-11 01:46:01.259] [metadataExpiration] [info] Scanning for expired metadata
15940 [2021-06-11 01:46:01.259] [metadataExpiration] [info] -- Will wake for next expiration in 7200sec
15940 [2021-06-11 01:46:10.697] [calContacts] [info] apidata.googleusercontent.com/caldav/v2/myaccount%40gmail.com/events/
15940 [2021-06-11 01:46:10.698] [calContacts] [info]   remote: 1 etags
15940 [2021-06-11 01:46:10.698] [calContacts] [info]    local: 0 etags
15940 [2021-06-11 01:46:10.698] [calContacts] [info]  deleted: 0
15940 [2021-06-11 01:46:10.698] [calContacts] [info]   needed: 1
15940 [2021-06-11 01:46:11.219] [background] [info] syncFolderUIDRange for [Gmail]/&1zTJwNG1-, UIDs: 1 - 113, Heavy: true
15940 [2021-06-11 01:46:11.695] [foreground] [info] Idle exited with code 0
15940 [2021-06-11 01:46:12.687] [foreground] [info] syncFolderChangesViaCondstore - [Gmail]/&yATMtLz0rQDVaA-: modseq 49816 to 49865, uidnext 1169 to 1170
15940 [2021-06-11 01:46:12.726] [background] [info] - remote=110, local=0
15940 [2021-06-11 01:46:13.029] [foreground] [info] syncFolderChangesViaCondstore - Changes since HMODSEQ 49816: 1 changed, 0 vanished
15940 [2021-06-11 01:46:13.066] [background] [info] syncFolderUIDRange for [Gmail]/&1zTJwNG1-, UIDs: 1 - 0, Heavy: false
15940 [2021-06-11 01:46:13.418] [background] [info] - remote=110, local=110
15940 [2021-06-11 01:46:13.419] [background] [info] Cleaning local cache and updating stats
15940 [2021-06-11 01:46:13.421] [background] [info] -- 0 message bodies deleted from local cache.
15940 [2021-06-11 01:46:13.747] [background] [info] syncFolderUIDRange for [Gmail]/&wqTTONVo-, UIDs: 1 - 125, Heavy: true
15940 [2021-06-11 01:46:14.229] [calContacts] [info] apidata.googleusercontent.com/caldav/v2/ddnissrfelq6gnrbdtp6ao93d1nmoqb4c5sk0pridtqn0bjm5phm2r35dpi62shectnmuprcckn66rrd%40virtual/events/
15940 [2021-06-11 01:46:14.229] [calContacts] [info]   remote: 5 etags
15940 [2021-06-11 01:46:14.229] [calContacts] [info]    local: 0 etags
15940 [2021-06-11 01:46:14.229] [calContacts] [info]  deleted: 0
15940 [2021-06-11 01:46:14.229] [calContacts] [info]   needed: 5
15940 [2021-06-11 01:46:14.664] [background] [info] - remote=119, local=0
15940 [2021-06-11 01:46:15.278] [background] [info] syncFolderUIDRange for [Gmail]/&wqTTONVo-, UIDs: 1 - 0, Heavy: false
15940 [2021-06-11 01:46:15.639] [background] [info] - remote=119, local=119
15940 [2021-06-11 01:46:15.641] [background] [info] Cleaning local cache and updating stats
15940 [2021-06-11 01:46:15.644] [background] [info] -- 0 message bodies deleted from local cache.
15940 [2021-06-11 01:46:15.644] [background] [info] Sync loop deleting unlinked messages with phase 2.
15940 [2021-06-11 01:46:15.645] [background] [info] Sync loop complete.
15940 [2021-06-11 01:46:15.645] [background] [info] Syncing folder list...
15940 [2021-06-11 01:46:16.296] [background] [info] syncFolderUIDRange for [Gmail]/&yATMtLz0rQDVaA-, UIDs: 1 - 419, Heavy: true
15940 [2021-06-11 01:46:18.805] [background] [info] - remote=354, local=1
15940 [2021-06-11 01:46:20.481] [background] [info] syncFolderUIDRange for [Gmail]/&yATMtLz0rQDVaA-, UIDs: 1169 - 1170, Heavy: true
15940 [2021-06-11 01:46:20.816] [background] [info] - remote=1, local=1
15940 [2021-06-11 01:46:25.618] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
15940 [2021-06-11 01:46:31.618] [background] [info] Cleaning local cache and updating stats
15940 [2021-06-11 01:46:31.624] [background] [info] -- 0 message bodies deleted from local cache.
15940 [2021-06-11 01:46:32.281] [background] [info] Sync loop deleting unlinked messages with phase 1.
15940 [2021-06-11 01:46:32.283] [background] [info] Sync loop complete.
15940 [2021-06-11 01:46:32.283] [background] [info] Syncing folder list...
15940 [2021-06-11 01:46:44.253] [background] [info] Sync loop deleting unlinked messages with phase 2.
15940 [2021-06-11 01:46:44.254] [background] [info] Sync loop complete.
15940 [2021-06-11 01:46:44.254] [background] [info] Syncing folder list...
15940 [2021-06-11 01:46:44.906] [background] [info] syncFolderUIDRange for [Gmail]/&yATMtLz0rQDVaA-, UIDs: 1170 - 1171, Heavy: true
15940 [2021-06-11 01:46:45.242] [background] [info] - remote=1, local=0
15940 [2021-06-11 01:46:46.290] [foreground] [info] Idle exited with code 0
15940 [2021-06-11 01:46:46.623] [foreground] [info] syncFolderChangesViaCondstore - [Gmail]/&yATMtLz0rQDVaA-: modseq 49865 to 49958, uidnext 1170 to 1171
15940 [2021-06-11 01:46:46.964] [foreground] [info] syncFolderChangesViaCondstore - Changes since HMODSEQ 49865: 1 changed, 0 vanished
15940 [2021-06-11 01:46:56.487] [background] [info] Sync loop deleting unlinked messages with phase 1.
15940 [2021-06-11 01:46:56.487] [background] [info] Sync loop complete.
15940 [2021-06-11 01:46:56.488] [background] [info] Syncing folder list...
15940 [2021-06-11 01:46:57.220] [background] [info] syncFolderUIDRange for [Gmail]/&yATMtLz0rQDVaA-, UIDs: 1170 - 1171, Heavy: true
15940 [2021-06-11 01:46:57.554] [background] [info] - remote=1, local=1
15940 [2021-06-11 01:47:00.457] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
15940 [2021-06-11 01:47:09.856] [background] [info] Sync loop deleting unlinked messages with phase 2.
15940 [2021-06-11 01:47:09.856] [background] [info] Sync loop complete.
15940 [2021-06-11 01:47:09.856] [background] [info] Syncing folder list...
15940 [2021-06-11 01:47:11.164] [background] [info] Sync loop deleting unlinked messages with phase 1.
15940 [2021-06-11 01:47:11.165] [background] [info] Sync loop complete.
15940 [2021-06-11 01:47:22.047] [main] [info] [local-44979a72-cdf4] Running ChangeUnreadTask performLocal:
15940 [2021-06-11 01:47:22.050] [main] [info] [local-44979a72-cdf4] -- Succeeded. Changing status to `remote`
15940 [2021-06-11 01:47:22.686] [foreground] [info] Idle exited with code 0
15940 [2021-06-11 01:47:22.687] [foreground] [info] [local-44979a72-cdf4] Running ChangeUnreadTask performRemote:
15940 [2021-06-11 01:47:23.236] [foreground] [info] [local-44979a72-cdf4] -- Succeeded. Changing status to `complete`
15940 [2021-06-11 01:47:23.573] [foreground] [info] syncFolderChangesViaCondstore - [Gmail]/&yATMtLz0rQDVaA-: modseq 49958 to 50026, uidnext 1171 to 1171
15940 [2021-06-11 01:47:23.915] [foreground] [info] syncFolderChangesViaCondstore - Changes since HMODSEQ 49958: 1 changed, 0 vanished
15940 [2021-06-11 01:47:23.925] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
15940 [2021-06-11 01:47:28.870] [main] [info] [local-160cd11c-8d1c] Running ChangeLabelsTask performLocal:
15940 [2021-06-11 01:47:28.882] [main] [info] [local-160cd11c-8d1c] -- Succeeded. Changing status to `remote`
15940 [2021-06-11 01:47:29.516] [foreground] [info] Idle exited with code 0
15940 [2021-06-11 01:47:29.517] [foreground] [info] [local-160cd11c-8d1c] Running ChangeLabelsTask performRemote:
15940 [2021-06-11 01:47:30.087] [foreground] [info] [local-160cd11c-8d1c] -- Succeeded. Changing status to `complete`
15940 [2021-06-11 01:47:30.427] [foreground] [info] syncFolderChangesViaCondstore - [Gmail]/&yATMtLz0rQDVaA-: modseq 50026 to 50077, uidnext 1171 to 1171
15940 [2021-06-11 01:47:30.770] [foreground] [info] syncFolderChangesViaCondstore - Changes since HMODSEQ 50026: 2 changed, 0 vanished
15940 [2021-06-11 01:47:30.775] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
15940 [2021-06-11 01:47:31.692] [main] [info] [local-b4b06da2-e725] Running ChangeUnreadTask performLocal:
15940 [2021-06-11 01:47:31.695] [main] [info] [local-b4b06da2-e725] -- Succeeded. Changing status to `remote`
15940 [2021-06-11 01:47:32.335] [foreground] [info] Idle exited with code 0
15940 [2021-06-11 01:47:32.336] [foreground] [info] [local-b4b06da2-e725] Running ChangeUnreadTask performRemote:
15940 [2021-06-11 01:47:32.881] [foreground] [info] [local-b4b06da2-e725] -- Succeeded. Changing status to `complete`
15940 [2021-06-11 01:47:33.227] [foreground] [info] syncFolderChangesViaCondstore - [Gmail]/&yATMtLz0rQDVaA-: modseq 50077 to 50174, uidnext 1171 to 1171
15940 [2021-06-11 01:47:33.571] [foreground] [info] syncFolderChangesViaCondstore - Changes since HMODSEQ 50077: 1 changed, 0 vanished
15940 [2021-06-11 01:47:33.577] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
4236 [2021-06-11 01:55:15.850] [main] [info] Identity created at 1516741397 - using ID Schema 0
4236 [2021-06-11 01:55:15.852] [main] [info] ------------- Starting Sync (myaccount@gmail.com) ---------------
4236 [2021-06-11 01:55:15.986] [metadata] [info] Metadata delta stream starting...
4236 [2021-06-11 01:55:18.938] [background] [info] Fetching XOAuth2 access token (gmail) for 66b037d7
4236 [2021-06-11 01:55:19.226] [background] [info] Marking all folders as `busy`
4236 [2021-06-11 01:55:19.227] [background] [info] Syncing folder list...
4236 [2021-06-11 01:55:22.297] [background] [info] Syncing folder list...
4236 [2021-06-11 01:55:22.957] [background] [info] syncFolderUIDRange for [Gmail]/&yATMtLz0rQDVaA-, UIDs: 684 - 1171, Heavy: false
4236 [2021-06-11 01:55:23.723] [background] [info] - remote=400, local=400
4236 [2021-06-11 01:55:24.063] [background] [info] syncFolderUIDRange for [Gmail]/&1zTJwNG1-, UIDs: 1 - 113, Heavy: false
4236 [2021-06-11 01:55:24.753] [background] [info] - remote=110, local=110
4236 [2021-06-11 01:55:25.083] [background] [info] syncFolderUIDRange for [Gmail]/&wqTTONVo-, UIDs: 1 - 125, Heavy: false
4236 [2021-06-11 01:55:25.296] [foreground] [info] syncFolderChangesViaCondstore - [Gmail]/&yATMtLz0rQDVaA-: modseq 50174 to 50215, uidnext 1171 to 1171
4236 [2021-06-11 01:55:25.778] [background] [info] - remote=119, local=119
4236 [2021-06-11 01:55:25.780] [background] [info] Sync loop deleting unlinked messages with phase 2.
4236 [2021-06-11 01:55:25.780] [background] [info] Sync loop complete.
4236 [2021-06-11 01:55:25.958] [foreground] [info] syncFolderChangesViaCondstore - Changes since HMODSEQ 50174: 0 changed, 0 vanished
4236 [2021-06-11 01:55:25.963] [foreground] [info] Idling on folder [Gmail]/&yATMtLz0rQDVaA-
4236 [2021-06-11 01:55:31.005] [metadataExpiration] [info] Scanning for expired metadata
4236 [2021-06-11 01:55:31.005] [metadataExpiration] [info] -- Will wake for next expiration in 7200sec

And, I guessed there is network or firewall problem. I allowed all mailspring firewall in private and public. But This action did not change anything.

image
image1121×631 29.5 KB

The last guess was there is some account sync cache problem. I did find and delete all mailspring related files and then reinstall. But the problem did not solved.

Hope there is a solution…

#2

Is this error also involved? This error is occurred on Account > Local data > rewrite cache.

image

#3

I have been having exactly this same issue! It’s like Mailspring has stopped storing the OAuth refresh token or something. My mail sync logs look as above, though occasionally they are more explicit in getting an HTTP 400 back from google OAuth for “invalid_grant”.

#4

In fact, I can see in the config.json that this is not stored:

    {"accounts": [
    {
      "id": "ACCOUNT ID",
      "metadata": [],
      "name": "MY NAME",
      "provider": "gmail",
      "emailAddress": "MY EMAIL ADDRESS",
      "settings": {
        "imap_host": "imap.gmail.com",
        "imap_port": 993,
        "imap_username": "MY EMAIL ADADRESS",
        "imap_security": "SSL / TLS",
        "imap_allow_insecure_ssl": false,
        "smtp_host": "smtp.gmail.com",
        "smtp_port": 587,
        "smtp_username": "MY EMAIL ADDRESS",
        "smtp_security": "STARTTLS",
        "smtp_allow_insecure_ssl": false,
        "refresh_client_id": "MY OAUTH CLIENT     ID.apps.googleusercontent.com"
      },
      "label": "MY EMAIL ADDRESS",
      "autoaddress": {
        "type": "bcc",
        "value": ""
      },
      "aliases": [],
      "syncState": "ok",
      "syncError": {
        "code": 3221226505,
        "error": {
          "stack": "Error: null5784 [2021-06-16 09:24:21.930] [background] [critical] \r\n***\r\n*** Mailspring Sync \r\n*** An exception occurred during program execution: \r\n*** {\"debuginfo\":\"https://www.googleapis.com/oauth2/v4/token RETURNED {\\n  \\\"error\\\": \\\"invalid_grant\\\",\\n  \\\"error_description\\\": \\\"Bad Request\\\"\\n}\",\"key\":\"Invalid Response Code: 400\",\"retryable\":false,\"what\":\"Unknown exception\"}\r\n***\r\n\r\r\n\n    at ChildProcess.onStreamCloseOrExit (file:///C:/Users/appveyor/AppData/Local/Temp/1/nylas-build/electron-packager/win32-ia32/Mailspring-win32-ia32/resources/app/src/mailsync-process.ts:301:17)\n    at ChildProcess.emit (events.js:210:5)\n    at ChildProcess.EventEmitter.emit (domain.js:476:20)\n    at Process.ChildProcess._handle.onexit   (internal/child_process.js:272:12)",
          "message": "null5784 [2021-06-16 09:24:21.930] [background] [critical] \r\n***\r\n*** Mailspring Sync \r\n*** An exception occurred     during program execution: \r\n*** {\"debuginfo\":\"https://www.googleapis.com/oauth2/v4/token RETURNED {\\n      \\\"error\\\": \\\"invalid_grant\\\",\\n  \\\"error_description\\\": \\\"Bad Request\\\"\\n}\",\"key\":\"Invalid Response Code: 400\",    \"retryable\":false,\"what\":\"Unknown exception\"}\r\n***\r\n\r\r\n"
        },
        "signal": null
      },
      "authedAt": 1623832356.727,
      "color": "",
      "__cls": "Account"
    },
// [...]
 ]}
#5

Thank you @majorsimon. Your replay encouraged me and i searched some more.

Here is the accounts parts inconfig.json codes:

"accounts": [
      {
        "id": "ACCOUNT_ID",
        "metadata": [],
        "name": "MY_NAME",
        "provider": "gmail",
        "emailAddress": "MY_EMAIL@gmail.com",
        "settings": {
          "imap_host": "imap.gmail.com",
          "imap_port": 993,
          "imap_username": "MY_EMAIL@gmail.com",
          "imap_security": "SSL / TLS",
          "imap_allow_insecure_ssl": false,
          "smtp_host": "smtp.gmail.com",
          "smtp_port": 587,
          "smtp_username": "MY_EMAIL@gmail.com",
          "smtp_security": "STARTTLS",
          "smtp_allow_insecure_ssl": false,
          "refresh_client_id": "MY_REFRESH_CLIENT_ID.apps.googleusercontent.com"
        },
        "label": "MY_EMAIL@gmail.com",
        "autoaddress": {
          "type": "bcc",
          "value": ""
        },
        "aliases": [],
        "syncState": "sync_error",
        "syncError": {
          "code": 1,
          "error": {
            "stack": "Error: Account is missing required fields:imap_password or refresh_token\n    at ChildProcess.onStreamCloseOrExit (file:///C:/Users/appveyor/AppData/Local/Temp/1/nylas-build/electron-packager/win32-ia32/Mailspring-win32-ia32/resources/app/src/mailsync-process.ts:293:21)\n    at ChildProcess.emit (events.js:210:5)\n    at ChildProcess.EventEmitter.emit (domain.js:476:20)\n    at Process.ChildProcess._handle.onexit (internal/child_process.js:272:12)",
            "message": "Account is missing required fields:imap_password or refresh_token"
          },
          "signal": null
        },
        "authedAt": 1623430253.809,
        "color": "",
        "__cls": "Account"
      }
    ],
    "accountsVersion": 17
  }

I looked up mailsync-process.ts on github and found where the problem was. It seems lastJSON parsing error from outbuffer.

I also googled about Process.ChildProcess._handle.onexit (internal/child_process.js:272:12). This seems like a node-gyp build error on windows because the node version is not compatible.

References:

#6

Finally I gave up in this problem and formatted my PC. Fortunately It works well.