Exporting All Collection Failed or UI is stuck at Processing

[tahmidbintaslim]

Hello, I am running the latest version Outline v0.73.1 Self Hosted Docker Version in my Linode (using Aapanel). I am using Postgres from my server but Redis connection (Free Plan) from https://app.redislabs.com/

The issue is when I tried to export all collection on v0.72.2, the UI shows Processing and keeps looping.
Yesterday, I upgraded to v0.73.1 and now it shows Failed. Access Denied.

Logs set to Debug. Here are the Error Logs when tried to export:

2023/11/16 23:34:36 [error] 173908#0: *153 no live upstreams while connecting to upstream, client: 103.177.247.200, server: mydomain.comc, request: ＂GET /realtime/?EIO＝4&transport＝websocket HTTP/1.1＂, upstream: ＂http://localhost/realtime/?EIO＝4&transport＝websocket＂, host: ＂mydomain.com＂
2023/11/16 23:34:37 [error] 173908#0: *154 no live upstreams while connecting to upstream, client: 103.177.247.200, server: mydomain.com, request: ＂GET /realtime/?EIO＝4&transport＝websocket HTTP/1.1＂, upstream: ＂http://localhost/realtime/?EIO＝4&transport＝websocket＂, host: ＂mydomain.com＂
2023/11/16 23:34:39 [error] 173908#0: *155 no live upstreams while connecting to upstream, client: 103.177.247.200, server: mydomain.com, request: ＂GET /realtime/?EIO＝4&transport＝websocket HTTP/1.1＂, upstream: ＂http://localhost/realtime/?EIO＝4&transport＝websocket＂, host: ＂mydomain.com＂
2023/11/16 23:34:39 [error] 173908#0: *156 no live upstreams while connecting to upstream, client: 103.177.247.200, server: mydomain.com, request: ＂GET /settings/export HTTP/2.0＂, upstream: ＂http://localhost/settings/export＂, host: ＂mydomain.com＂
2023/11/16 23:34:39 [error] 173908#0: *156 no live upstreams while connecting to upstream, client: 103.177.247.200, server: mydomain.com, request: ＂GET /favicon.ico HTTP/2.0＂, upstream: ＂http://localhost/favicon.ico＂, host: ＂mydomain.com＂, referrer: ＂https://mydomain.com/settings/export＂
2023/11/16 23:34:41 [error] 173908#0: *156 no live upstreams while connecting to upstream, client: 103.177.247.200, server: mydomain.com, request: ＂GET /settings/export HTTP/2.0＂, upstream: ＂http://localhost/settings/export＂, host: ＂mydomain.com＂
2023/11/16 23:34:41 [error] 173908#0: *156 no live upstreams while connecting to upstream, client: 103.177.247.200, server: mydomain.com, request: ＂GET /favicon.ico HTTP/2.0＂, upstream: ＂http://localhost/favicon.ico＂, host: ＂mydomain.com＂, referrer: ＂https://mydomain.com/settings/export＂
2023/11/17 01:51:42 [crit] 173908#0: *511 SSL_do_handshake() failed (SSL: error:141CF06C:SSL routines:tls_parse_ctos_key_share:bad key share) while SSL handshaking, client: 159.65.58.104, server: 0.0.0.0:443
2023/11/17 04:05:49 [crit] 173908#0: *751 SSL_do_handshake() failed (SSL: error:141CF06C:SSL routines:tls_parse_ctos_key_share:bad key share) while SSL handshaking, client: 104.152.52.134, server: 0.0.0.0:443
2023/11/17 07:14:32 [crit] 173908#0: *1087 SSL_do_handshake() failed (SSL: error:141CF06C:SSL routines:tls_parse_ctos_key_share:bad key share) while SSL handshaking, client: 192.241.208.49, server: 0.0.0.0:443
2023/11/17 08:50:10 [crit] 173908#0: *1301 SSL_do_handshake() failed (SSL: error:141CF06C:SSL routines:tls_parse_ctos_key_share:bad key share) while SSL handshaking, client: 184.105.247.254, server: 0.0.0.0:443
2023/11/17 10:54:12 [crit] 173908#0: *1450 SSL_do_handshake() failed (SSL: error:141CF06C:SSL routines:tls_parse_ctos_key_share:bad key share) while SSL handshaking, client: 212.102.40.218, server: 0.0.0.0:443

[tommoor]

The hanging processing bug was fixed so that the error is correctly reported, which is what you're seeing since upgrading. The logs you posted are not Outline logs, if you can post the logs from the Outline server they should offer more details.

This is likely some sort of permissions issue with your file storage.

[tahmidbintaslim]

Thank you for the reply @tommoor . I can find the logs from docker and it shows these logs:

{
{"label":"http","level":"info","message":" <-- POST /api/auth.info"}
{"label":"http","level":"info","message":" --> POST /api/auth.info 200 85ms 1.92kb"}
{"label":"worker","level":"info","message":"ValidateSSOAccessTask running","userId":"88ef5224-bc5a-4b07-a273-9e2c97a38434"}
{"label":"authentication","level":"debug","message":"Recently validated, skipping access token validation"}
{"label":"http","level":"info","message":" <-- POST /api/notifications.list"}
{"label":"http","level":"info","message":" <-- POST /api/documents.drafts"}
{"label":"http","level":"info","message":" --> POST /api/documents.drafts 200 16ms 1.81kb"}
{"label":"http","level":"info","message":" --> POST /api/notifications.list 200 25ms 166b"}
{"label":"http","level":"info","message":" <-- POST /api/collections.list"}
{"label":"http","level":"info","message":" <-- POST /api/stars.list"}
{"label":"http","level":"info","message":" --> POST /api/stars.list 200 21ms 158b"}
{"label":"http","level":"info","message":" --> POST /api/collections.list 200 31ms 5.65kb"}
{"label":"http","level":"info","message":" <-- POST /api/documents.list"}
{"label":"http","level":"info","message":" <-- POST /api/documents.info"}
{"label":"http","level":"info","message":" --> POST /api/documents.list 200 26ms 137b"}
{"label":"http","level":"info","message":" --> POST /api/documents.info 200 27ms 1.77kb"}
{"label":"http","level":"info","message":" <-- POST /api/documents.list"}
{"label":"http","level":"info","message":" <-- POST /api/subscriptions.list"}
{"label":"http","level":"info","message":" <-- POST /api/views.list"}
{"label":"http","level":"info","message":" <-- POST /api/comments.list"}
{"label":"websockets","level":"debug","message":"Authenticated socket sW8z-PCjKNz86FmxAAAN"}
{"label":"http","level":"info","message":" <-- POST /api/shares.info"}
{"label":"http","level":"info","message":" --> POST /api/documents.list 200 64ms 137b"}
{"label":"http","level":"info","message":" --> POST /api/subscriptions.list 200 52ms 377b"}
{"label":"http","level":"info","message":" --> POST /api/views.list 200 46ms 646b"}
{"label":"http","level":"info","message":" --> POST /api/comments.list 200 42ms 139b"}
{"label":"http","level":"info","message":" --> POST /api/shares.info 204 31ms "}
{"label":"http","level":"info","message":" <-- POST /api/integrations.list"}
{"label":"http","level":"info","message":" --> POST /api/integrations.list 200 5ms 129b"}
{"label":"multiplayer","level":"info","message":"New connection to "document.0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1""}
{"label":"database","level":"info","message":"Document 0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1 is in database state"}
{"label":"multiplayer","level":"info","message":"Loaded document "document.0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1"","userId":"88ef5224-bc5a-4b07-a273-9e2c97a38434"}
{"label":"multiplayer","level":"debug","message":"1 connections to "document.0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1""}
{"label":"multiplayer","level":"info","message":"Authenticated connection to "document.0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1""}
{"label":"http","level":"info","message":" <-- POST /api/views.create"}
{"label":"http","level":"info","message":" --> POST /api/views.create 200 20ms 645b"}
{"label":"http","level":"info","message":" <-- POST /api/collections.documents"}
{"label":"http","level":"info","message":" --> POST /api/collections.documents 200 8ms 799b"}
{"attempt":0,"event":{"actorId":"88ef5224-bc5a-4b07-a273-9e2c97a38434","collectionId":null,"createdAt":"2023-11-17T15:21:39.196Z","data":{"title":"Demo"},"documentId":"0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1","id":"fd17f450-6d69-44ef-8cde-8d8d88cd5eea","ip":"45.125.223.81","modelId":"501ada83-fce6-4bc6-8d61-4eea10c6950f","name":"views.create","teamId":"3645960e-02c8-4e89-aaa6-642729fc287b","userId":null},"label":"worker","level":"info","message":"Processing views.create"}
{"label":"http","level":"info","message":" <-- POST /api/collections.documents"}
{"label":"http","level":"info","message":" --> POST /api/collections.documents 200 8ms 816b"}

{"event":{"actorId":"88ef5224-bc5a-4b07-a273-9e2c97a38434","collectionId":null,"createdAt":"2023-11-17T15:21:39.196Z","data":{"title":"Demo"},"documentId":"0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1","id":"fd17f450-6d69-44ef-8cde-8d8d88cd5eea","ip":"45.125.223.81","modelId":"501ada83-fce6-4bc6-8d61-4eea10c6950f","name":"views.create","teamId":"3645960e-02c8-4e89-aaa6-642729fc287b","userId":null},"label":"worker","level":"info","message":"WebhookProcessor running views.create"}
{"label":"multiplayer","level":"debug","message":"0 connections to "document.0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1""}
{"label":"multiplayer","level":"debug","message":"No changes for document.0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1"}
{"label":"multiplayer","level":"info","message":"Closed connection to "document.0e9a41e6-5618-4bc9-ae51-d63ee9e0b5e1"","userId":"88ef5224-bc5a-4b07-a273-9e2c97a38434"}

{"label":"http","level":"info","message":" <-- POST /api/notifications.list"}
{"label":"http","level":"info","message":" --> POST /api/notifications.list 200 11ms 166b"}
{"label":"http","level":"info","message":" <-- POST /api/fileOperations.list"}
{"label":"http","level":"info","message":" --> POST /api/fileOperations.list 200 15ms 11.14kb"}
{"label":"http","level":"info","message":" <-- POST /api/collections.export_all"}
{"label":"http","level":"info","message":" --> POST /api/collections.export_all 200 11ms 693b"}

{"attempt":0,"event":{"actorId":"88ef5224-bc5a-4b07-a273-9e2c97a38434","collectionId":null,"createdAt":"2023-11-17T15:21:52.487Z","data":{"format":"html","type":"export"},"documentId":null,"id":"deff3d43-672e-4fb3-ab3a-9cec4e7c3c59","ip":"45.125.223.81","modelId":"ceb4cfcd-666c-4718-bf73-aa18e35c6a52","name":"fileOperations.create","teamId":"3645960e-02c8-4e89-aaa6-642729fc287b","userId":null},"label":"worker","level":"info","message":"Processing fileOperations.create"}
{"event":{"actorId":"88ef5224-bc5a-4b07-a273-9e2c97a38434","collectionId":null,"createdAt":"2023-11-17T15:21:52.487Z","data":{"format":"html","type":"export"},"documentId":null,"id":"deff3d43-672e-4fb3-ab3a-9cec4e7c3c59","ip":"45.125.223.81","modelId":"ceb4cfcd-666c-4718-bf73-aa18e35c6a52","name":"fileOperations.create","teamId":"3645960e-02c8-4e89-aaa6-642729fc287b","userId":null},"label":"worker","level":"info","message":"FileOperationCreatedProcessor running fileOperations.create"}
{"fileOperationId":"ceb4cfcd-666c-4718-bf73-aa18e35c6a52","label":"worker","level":"info","message":"ExportHTMLZipTask running"}
{"label":"task","level":"info","message":"ExportTask fetching data for ceb4cfcd-666c-4718-bf73-aa18e35c6a52"}
{"event":{"actorId":"88ef5224-bc5a-4b07-a273-9e2c97a38434","collectionId":null,"createdAt":"2023-11-17T15:21:52.487Z","data":{"format":"html","type":"export"},"documentId":null,"id":"deff3d43-672e-4fb3-ab3a-9cec4e7c3c59","ip":"45.125.223.81","modelId":"ceb4cfcd-666c-4718-bf73-aa18e35c6a52","name":"fileOperations.create","teamId":"3645960e-02c8-4e89-aaa6-642729fc287b","userId":null},"label":"worker","level":"info","message":"WebhookProcessor running fileOperations.create"}
{"includeAttachments":true,"label":"task","level":"info","message":"ExportTask processing data for ceb4cfcd-666c-4718-bf73-aa18e35c6a52"}

{"label":"task","level":"debug","message":"Start adding 0 documents to archive"}

{"documentId":"responsibilities-W10tJjMkZ4","label":"task","level":"debug","message":"Adding document to archive"}
{"documentId":"okrs-aFNT6s4XWI","label":"task","level":"debug","message":"Adding document to archive"}
{"documentId":"work-process-nyeUMy6048","label":"task","level":"debug","message":"Adding document to archive"}
{"documentId":"responsibilities-vxggjKbKVN","label":"task","level":"debug","message":"Adding document to archive"}

{"attempt":0,"event":{"actorId":"88ef5224-bc5a-4b07-a273-9e2c97a38434","createdAt":"2023-11-17T15:21:52.955Z","data":{"collectionId":null,"createdAt":"2023-11-17T15:21:52.485Z","error":null,"format":"html","id":"ceb4cfcd-666c-4718-bf73-aa18e35c6a52","name":"FileName-export.zip","size":"0","state":"creating","type":"export","updatedAt":"2023-11-17T15:21:52.485Z","user":{"avatarUrl":"[Filtered]","color":"#F5BE31","createdAt":"2023-11-07T15:21:01.820Z","id":"88ef5224-bc5a-4b07-a273-9e2c97a38434","isAdmin":true,"isSuspended":false,"isViewer":false,"lastActiveAt":"2023-11-17T15:21:31.451Z","name":"software test","updatedAt":"2023-11-17T15:21:31.451Z"}},"id":"9852adad-3f39-49c4-8675-0e93ea41dd6b","modelId":"ceb4cfcd-666c-4718-bf73-aa18e35c6a52","name":"fileOperations.update","teamId":"3645960e-02c8-4e89-aaa6-642729fc287b"},"label":"worker","level":"info","message":"Processing fileOperations.update"}

Access Denied -->

{"documentId":"5-get-information-DFlluYBUTL","label":"task","level":"debug","message":"Adding document to archive"}
{"error":"Access Denied","level":"error","message":"Unhandled promise rejection","stack":"AccessDenied: Access Denied\n at Request.extractError (/opt/outline/node_modules/aws-sdk/lib/services/s3.js:711:35)\n at Request.callListeners (/opt/outline/node_modules/aws-sdk/lib/sequential_executor.js:106:20)\n at Request.emit (/opt/outline/node_modules/aws-sdk/lib/sequential_executor.js:78:10)\n at Request.emit (/opt/outline/node_modules/aws-sdk/lib/request.js:686:14)\n at Request.transition (/opt/outline/node_modules/aws-sdk/lib/request.js:22:10)\n at AcceptorStateMachine.runTo (/opt/outline/node_modules/aws-sdk/lib/state_machine.js:14:12)\n at /opt/outline/node_modules/aws-sdk/lib/state_machine.js:26:10\n at Request. (/opt/outline/node_modules/aws-sdk/lib/request.js:38:9)\n at Request. (/opt/outline/node_modules/aws-sdk/lib/request.js:688:12)\n at Request.callListeners (/opt/outline/node_modules/aws-sdk/lib/sequential_executor.js:116:18)\n at Request.emit (/opt/outline/node_modules/aws-sdk/lib/sequential_executor.js:78:10)\n at Request.emit (/opt/outline/node_modules/aws-sdk/lib/request.js:686:14)\n at Request.transition (/opt/outline/node_modules/aws-sdk/lib/request.js:22:10)\n at AcceptorStateMachine.runTo (/opt/outline/node_modules/aws-sdk/lib/state_machine.js:14:12)\n at /opt/outline/node_modules/aws-sdk/lib/state_machine.js:26:10\n at Request. (/opt/outline/node_modules/aws-sdk/lib/request.js:38:9)\n at Request. (/opt/outline/node_modules/aws-sdk/lib/request.js:688:12)\n at Request.callListeners (/opt/outline/node_modules/aws-sdk/lib/sequential_executor.js:116:18)\n at callNextListener (/opt/outline/node_modules/aws-sdk/lib/sequential_executor.js:96:12)\n at IncomingMessage.onEnd (/opt/outline/node_modules/aws-sdk/lib/event_listeners.js:417:13)\n at IncomingMessage.emit (node:events:529:35)\n at IncomingMessage.emit (node:domain:489:12)\n at endReadableNT (node:internal/streams/readable:1368:12)\n at process.processTicksAndRejections (node:internal/process/task_queues:82:21)"}

[tommoor]

The error from the S3 library is "Access denied" – there isn't really any other details to go off unfortunately.

It seems as though your SMTP authentication is also wrong, but that would be a red herring here.

[tahmidbintaslim]

Thank you for pointing out the S3 and SMTP issue. @tommoor

[tahmidbintaslim]

@tommoor Also, let me know how can I clear or remove those running/processing export task that shows in UI?

[tommoor]

You would need to delete them in the database directly, in the file_operations table

[tahmidbintaslim]

Thanks for the exact info. I will do it accordingly @tommoor