Internal server error after starting Pydio Cells


#1

I installed Pydio Cells 1.21 on CentOS 7 with MySQL 5.7. Install completed successfully and I have all the necessary ports open, but I am getting internal server errors while Cells is starting for the first time, see below. What might it be?

WARNING: File descriptor limit 1024 is too low for production servers. At least 8192 is recommended. Fix with “ulimit -n 8192”.
2018-11-25T08:22:41.261-0500 INFO pydio.grpc.data.objects started
2018-11-25T08:22:41.263-0500 INFO pydio.grpc.chat started
2018-11-25T08:22:41.320-0500 INFO pydio.grpc.jobs started
2018-11-25T08:22:41.321-0500 INFO pydio.grpc.data.sync started
2018-11-25T08:22:41.325-0500 INFO pydio.grpc.update started
2018-11-25T08:22:41.327-0500 INFO pydio.grpc.log started
2018-11-25T08:22:41.330-0500 INFO pydio.grpc.docstore started
2018-11-25T08:22:42.207-0500 INFO pydio.web.statics started
2018-11-25T08:22:42.264-0500 INFO pydio.gateway.proxy started
2018-11-25T08:22:42.309-0500 INFO pydio.grpc.acl started
2018-11-25T08:22:42.401-0500 INFO pydio.grpc.meta started
2018-11-25T08:22:42.756-0500 INFO pydio.grpc.user-key started
2018-11-25T08:22:51.336-0500 INFO pydio.grpc.user-meta started
2018-11-25T08:22:51.337-0500 INFO pydio.grpc.user-meta Inserting default namespace for metadata
2018-11-25T08:22:51.337-0500 INFO pydio.grpc.config started
2018-11-25T08:22:51.370-0500 INFO pydio.grpc.tasks started
2018-11-25T08:22:51.372-0500 INFO pydio.grpc.tree started
2018-11-25T08:22:51.374-0500 INFO pydio.gateway.websocket started
2018-11-25T08:22:51.511-0500 INFO pydio.grpc.mailer Starting mailer with queue 'boltdb’
2018-11-25T08:22:51.511-0500 INFO pydio.grpc.mailer Starting mailer with sender 'smtp’
2018-11-25T08:22:51.512-0500 INFO pydio.grpc.mailer started
2018-11-25T08:22:51.512-0500 INFO pydio.grpc.mailer Registering default job for consuming mailer queue
2018-11-25T08:22:51.514-0500 ERROR pydio.grpc.tasks Streamer PutTaskStream {“error”: “{“id”:“go.micro.client”,“code”:500,“detail”:“none available”,“status”:“Internal Server Error”}”}
2018-11-25T08:22:58.357-0500 INFO pydio.grpc.data.index started
2018-11-25T08:22:58.486-0500 INFO pydio.grpc.timer started
2018-11-25T08:22:58.866-0500 INFO pydio.grpc.activity started
2018-11-25T08:22:58.866-0500 INFO pydio.grpc.activity Registering default job for creating activities digests
2018-11-25T08:22:59.037-0500 INFO pydio.grpc.timer Registering Job{“job”: “archive-changes-job”}
2018-11-25T08:22:59.037-0500 INFO pydio.grpc.timer Registering Job{“job”: “flush-mailer-queue”}
2018-11-25T08:22:59.038-0500 INFO pydio.grpc.timer Registering Job{“job”: “internal-prune-jobs”}
2018-11-25T08:22:59.186-0500 INFO pydio.grpc.versions started
2018-11-25T08:22:59.186-0500 INFO pydio.grpc.versions Inserting default versioning policies
2018-11-25T08:23:00.269-0500 INFO pydio.grpc.role started
2018-11-25T08:23:06.076-0500 INFO pydio.gateway.dav started
2018-11-25T08:23:06.203-0500 INFO pydio.grpc.search started
2018-11-25T08:23:06.273-0500 INFO pydio.grpc.workspace started
2018-11-25T08:23:06.274-0500 INFO pydio.grpc.changes started
2018-11-25T08:23:06.306-0500 INFO pydio.gateway.wopi started
2018-11-25T08:23:06.307-0500 INFO pydio.gateway.data started
2018-11-25T08:23:06.311-0500 INFO pydio.grpc.role Created default role Root Group
2018-11-25T08:23:06.717-0500 INFO pydio.grpc.data-key started
2018-11-25T08:23:06.795-0500 INFO pydio.grpc.data.objects.local1 started
2018-11-25T08:23:06.816-0500 INFO pydio.grpc.role - Policies added for role Root Group
2018-11-25T08:23:06.795-0500 INFO pydio.grpc.data.sync.cellsdata started
2018-11-25T08:23:06.952-0500 INFO pydio.grpc.data.objects.local1 Starting objects service local1
2018-11-25T08:23:07.081-0500 INFO pydio.grpc.user started
2018-11-25T08:23:07.118-0500 INFO pydio.grpc.policy started
2018-11-25T08:23:07.158-0500 INFO pydio.grpc.user Initialization: creating admin user: admin
2018-11-25T08:23:07.376-0500 INFO pydio.grpc.policy Inserted default policies
2018-11-25T08:23:12.311-0500 INFO pydio.grpc.auth started
2018-11-25T08:23:14.189-0500 INFO pydio.grpc.auth Inserting pruning job for revoked token and reset password tokens
2018-11-25T08:23:20.589-0500 INFO pydio.rest.update started
2018-11-25T08:23:20.647-0500 INFO pydio.rest.search started
2018-11-25T08:23:20.671-0500 INFO pydio.rest.log started
2018-11-25T08:23:20.475-0500 INFO pydio.rest.meta started
2018-11-25T08:23:20.174-0500 INFO pydio.rest.workspace started
2018-11-25T08:23:20.742-0500 INFO pydio.grpc.changes Installing Default Job for Changes Resync
2018-11-25T08:23:20.744-0500 INFO pydio.rest.user started
2018-11-25T08:23:20.554-0500 INFO pydio.rest.jobs started
2018-11-25T08:23:20.858-0500 INFO pydio.rest.role started
2018-11-25T08:23:20.858-0500 INFO pydio.rest.config started
2018-11-25T08:23:20.881-0500 INFO pydio.rest.frontend started
2018-11-25T08:23:20.899-0500 INFO pydio.rest.tree started
2018-11-25T08:23:20.976-0500 INFO pydio.rest.activity started
2018-11-25T08:23:21.047-0500 INFO pydio.rest.policy started
2018-11-25T08:23:21.047-0500 INFO pydio.rest.graph started
2018-11-25T08:23:21.723-0500 INFO pydio.rest.user-meta started
2018-11-25T08:23:22.057-0500 INFO pydio.rest.mailer started
2018-11-25T08:23:22.957-0500 INFO pydio.rest.acl started
2018-11-25T08:23:23.284-0500 INFO pydio.rest.share started
2018-11-25T08:23:23.759-0500 INFO pydio.rest.changes started
2018-11-25T08:23:25.223-0500 INFO pydio.rest.auth started
2018-11-25T08:23:27.229-0500 INFO pydio.grpc.auth config using log level: debug
2018-11-25T08:23:29.076-0500 INFO pydio.rest.workspace Creating a Personal workspace
**2018-11-25T08:23:29.174-0500 INFO pydio.grpc.data.index.pydiods1 2018-11-25T08:23:29.117-0500 INFO Creating root node in index **
2018-11-25T08:23:29.188-0500 INFO pydio.rest.workspace Creating a Common Files workspace on pydiods1
2018-11-25T08:23:29.209-0500 INFO pydio.grpc.data.index.pydiods1 started
**2018-11-25T08:23:29.456-0500 INFO pydio.grpc.auth config storage: **
2018-11-25T08:23:29.456-0500 INFO pydio.grpc.auth config static client: cells-front
2018-11-25T08:23:29.457-0500 INFO pydio.grpc.auth config connector: pydio
2018-11-25T08:23:29.457-0500 INFO pydio.grpc.auth config response types accepted: [code token id_token]
2018-11-25T08:23:29.469-0500 INFO pydio.grpc.auth config id tokens valid for: 10m0s
2018-11-25T08:23:29.501-0500 INFO pydio.grpc.auth keys expired, rotating
2018-11-25T08:23:29.883-0500 INFO pydio.grpc.data.sync.pydiods1 started
2018-11-25T08:23:29.945-0500 INFO pydio.grpc.data.sync.personal started
2018-11-25T08:23:30.821-0500 INFO pydio.grpc.auth keys rotated, next rotation: 2018-11-25 19:23:30.785964093 +0000 UTC
2018-11-25T08:23:30.821-0500 INFO pydio.grpc.auth listening (http) on 0.0.0.0:39871
2018-11-25T08:23:31.127-0500 INFO pydio.grpc.role - ACLS set for role Root Group
2018-11-25T08:23:31.168-0500 INFO pydio.grpc.role Created default role Administrators
2018-11-25T08:23:31.186-0500 INFO pydio.grpc.role - Policies added for role Administrators
2018-11-25T08:23:31.489-0500 INFO pydio.grpc.role Role [admin role] has been updated {“MsgId”: “53”, “RoleUuid”: “1f5bf75e-7af1-4bb1-a77d-cf844cd7d64b”}
2018-11-25T08:23:31.489-0500 INFO pydio.grpc.user Initialization: creating s3 anonymous user
2018-11-25T08:23:36.419-0500 INFO pydio.grpc.data.sync.pydiods1 Create job to start datasource resync
2018-11-25T08:23:36.438-0500 INFO pydio.grpc.tasks Run Job resync-ds-pydiods1 on timer event
2018-11-25T08:23:36.689-0500 INFO pydio.grpc.data.sync.pydiods1 Listing all S3 objects for path {“bucket”: “pydiods1”, “path”: “”}
2018-11-25T08:23:36.714-0500 INFO pydio.grpc.data.index.pydiods1 Opening Indexation Session 509e1526-f0b5-11e8-9005-000c29e621e5
2018-11-25T08:23:36.715-0500 INFO pydio.grpc.data.index.pydiods1 Closing Indexation Session 509e1526-f0b5-11e8-9005-000c29e621e5
2018-11-25T08:23:36.716-0500 INFO pydio.grpc.data.index.pydiods1 Sent all events event on topic
2018-11-25T08:23:39.235-0500 INFO pydio.grpc.role - ACLS set for role Administrators
2018-11-25T08:23:39.238-0500 INFO pydio.grpc.role Created default role External Users
2018-11-25T08:23:39.240-0500 INFO pydio.grpc.role - Policies added for role External Users
2018-11-25T08:23:39.679-0500 INFO pydio.grpc.role Role [pydio.anon.user role] has been updated {“MsgId”: “53”, “RoleUuid”: “786feb5d-6c58-4e31-841b-13bf65a4df3d”}
2018-11-25T08:23:47.328-0500 INFO pydio.grpc.role - ACLS set for role External Users
2018-11-25T08:23:47.329-0500 INFO pydio.grpc.role Created default role Minisite Permissions
2018-11-25T08:23:47.331-0500 INFO pydio.grpc.role - Policies added for role Minisite Permissions
2018-11-25T08:23:55.371-0500 INFO pydio.grpc.role - ACLS set for role Minisite Permissions
2018-11-25T08:23:55.373-0500 INFO pydio.grpc.role Created default role Minisite (Download Disabled)
2018-11-25T08:23:55.374-0500 INFO pydio.grpc.role - Policies added for role Minisite (Download Disabled)
**2018-11-25T08:23:59.694-0500 INFO pydio.grpc.data.index.personal 2018-11-25T08:23:59.676-0500 INFO Creating root node in index **
**2018-11-25T08:23:59.710-0500 INFO pydio.grpc.data.index.cellsdata 2018-11-25T08:23:59.710-0500 INFO Creating root node in index **
2018-11-25T08:24:01.667-0500 INFO pydio.grpc.data.index.personal started
2018-11-25T08:24:02.503-0500 INFO pydio.grpc.data.index.cellsdata started
2018-11-25T08:24:02.687-0500 INFO pydio.grpc.data.sync.cellsdata Create job to start datasource resync
2018-11-25T08:24:04.650-0500 INFO pydio.grpc.tasks Run Job resync-ds-cellsdata on timer event
2018-11-25T08:24:04.901-0500 INFO pydio.grpc.role - ACLS set for role Minisite (Download Disabled)
2018-11-25T08:24:05.156-0500 INFO pydio.grpc.data.sync.cellsdata Listing all S3 objects for path {“bucket”: “cellsdata”, “path”: “”}
2018-11-25T08:24:05.282-0500 INFO pydio.grpc.data.index.cellsdata Opening Indexation Session 61a26233-f0b5-11e8-96b8-000c29e621e5
2018-11-25T08:24:05.291-0500 INFO pydio.grpc.data.index.cellsdata Closing Indexation Session 61a26233-f0b5-11e8-96b8-000c29e621e5
2018-11-25T08:24:05.293-0500 INFO pydio.grpc.data.index.cellsdata Sent all events event on topic
2018-11-25T08:24:06.559-0500 INFO pydio.grpc.data.sync.personal Create job to start datasource resync
2018-11-25T08:24:06.610-0500 INFO pydio.grpc.tasks Run Job resync-ds-personal on timer event
2018-11-25T08:24:06.739-0500 INFO pydio.grpc.data.sync.personal Listing all S3 objects for path {“bucket”: “personal”, “path”: “”}
2018-11-25T08:24:06.745-0500 INFO pydio.grpc.data.index.personal Opening Indexation Session 6284b9de-f0b5-11e8-865e-000c29e621e5
2018-11-25T08:24:06.756-0500 INFO pydio.grpc.data.index.personal Closing Indexation Session 6284b9de-f0b5-11e8-865e-000c29e621e5
2018-11-25T08:24:06.758-0500 INFO pydio.grpc.data.index.personal Sent all events event on topic
2018-11-25T08:24:56.566-0500 ERROR pydio.rest.config Ladon validation failed: {“id”:“go.micro.client”,“code”:500,“detail”:“none available”,“status”:“Internal Server Error”} {“error”: “{“id”:“go.micro.client”,“code”:500,“detail”:“none available”,“status”:“Internal Server Error”}”}
::1 - - [25/Nov/2018:08:24:54 -0500] “GET /config/discovery HTTP/1.1” 401 14 “https://192.168.1.212/” "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36"
2018-11-25T08:25:02.431-0500 ERROR Error while applying modifiers to registry! {“error”: “{“id”:“go.micro.client”,“code”:500,“detail”:“none available”,“status”:“Internal Server Error”}”}
2018-11-25T08:25:03.510-0500 INFO http: proxy error: context canceled
::1 - - [25/Nov/2018:08:25:02 -0500] “GET /config/discovery HTTP/1.1” 502 0 “https://192.168.1.212/” "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36"
2018-11-25T08:25:03.531-0500 ERROR pydio.rest.config Ladon validation failed: context canceled {“error”: “context canceled”}
2018-11-25T08:25:17.068-0500 INFO pydio.grpc.tasks Run Job flush-mailer-queue on timer event Iso8601Schedule:"R/2012-06-04T19:25:16.828696-07:00/PT5M"


#2

Hi,
when you say first time does it mean that it disappears if you start -> stop and redo the process?


#3

No, if I stop the server and start it again I get the same set of errors. The web page is stuck on the Loading… screen.


#4

Hi,
Check in DB >> ladon_policy
Do you have any record in this table?

DB must be empty before starting again


#5

I do have many rows in that table. When I try to DELETE FROM ladon_policy I get the following error:

Cannot delete or update a parent row: a foreign key constraint fails (cells.idm_policy_rel, CONSTRAINT idm_policy_rel_ibfk_2 FOREIGN KEY (policy_id) REFERENCES ladon_policy (id))


#6

Hi,

Try to drop database and create new one


#7

I have tried installing the system from scratch after restoring my fresh VM snapshot, still no dice. I’m thinking I may not have a dependency installed, but I followed the install guide properly.


#8

can you try to raise the ulimit ? This may be linked.


#9

Thanks for your reply, Charles. Unfortunately, I have decided to use another file sharing platform and will miss the features in Pydio.