Fresh mastodon install: error message in browser


#1

Hallo,

I’ve just installed Mastodon following the production guide on a Ubuntu 16.04 server. After completing the setup I’ve entered my domain in the browser.

I get redirected to the about page (example.com/about) and an error message is displayed (We’re sorry, but something went wrong on our end.)

How can I find out what went wrong? Are there any logs? The Nginx error log is empty.

Can someone help me?


#2

Do you have logs from puma, this means from mastodon-web.service in your setup?

journalctl -u mastodon-web.service 

might bring up something interesting.

Also the startup of the mastodon-web may take a while, make sure wait a bit before trying it from the browser.


#3

Here is everything related to puma in the journal:

Jan 03 17:33:01 example.com bundle[1068]: [1068] Puma starting in cluster mode...

Jan 03 22:58:40 example.com bundle[1068]: [e1e990ec-949e-477e-8e17-143f040b73a0] vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/configuration.rb:225:in `call'
Jan 03 22:58:40 example.com bundle[1068]: [e1e990ec-949e-477e-8e17-143f040b73a0] vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:624:in `handle_request'
Jan 03 22:58:40 example.com bundle[1068]: [e1e990ec-949e-477e-8e17-143f040b73a0] vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:438:in `process_client'
Jan 03 22:58:40 example.com bundle[1068]: [e1e990ec-949e-477e-8e17-143f040b73a0] vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/server.rb:302:in `block in run'
Jan 03 22:58:40 example.com bundle[1068]: [e1e990ec-949e-477e-8e17-143f040b73a0] vendor/bundle/ruby/2.4.0/gems/puma-3.11.0/lib/puma/thread_pool.rb:120:in `block in spawn_thread'

I’ve tried as well to restart services and the whole server but with no effect. Here is the output of systemctl status mastodon-*.service:

mastodon-web.service - mastodon-web
   Loaded: loaded (/etc/systemd/system/mastodon-web.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2018-01-04 14:59:35 CET; 32s ago
 Main PID: 12249 (bundle)
   CGroup: /system.slice/mastodon-web.service
           ├─12249 puma 3.11.0 (tcp://0.0.0.0:3000) [live]                                                                                  
           ├─12273 puma: cluster worker 0: 12249 [live]                                                                                     
           └─12287 puma: cluster worker 1: 12249 [live]                                                                                     

Jan 04 14:59:36 example.com bundle[12249]: [12249] * Version 3.11.0 (ruby 2.4.2-p198), codename: Love Song
Jan 04 14:59:36 example.com bundle[12249]: [12249] * Min threads: 5, max threads: 5
Jan 04 14:59:36 example.com bundle[12249]: [12249] * Environment: production
Jan 04 14:59:36 example.com bundle[12249]: [12249] * Process workers: 2
Jan 04 14:59:36 example.com bundle[12249]: [12249] * Preloading application
Jan 04 14:59:41 example.com bundle[12249]: Creating scope :cache_ids. Overwriting existing method Notification.cache_ids.
Jan 04 14:59:42 example.com bundle[12249]: [12249] * Listening on tcp://0.0.0.0:3000
Jan 04 14:59:42 example.com bundle[12249]: [12249] Use Ctrl-C to stop
Jan 04 14:59:42 example.com bundle[12249]: [12249] - Worker 0 (pid: 12273) booted, phase: 0
Jan 04 14:59:42 example.com bundle[12249]: [12249] - Worker 1 (pid: 12287) booted, phase: 0

● mastodon-streaming.service - mastodon-streaming
   Loaded: loaded (/etc/systemd/system/mastodon-streaming.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2018-01-03 17:32:58 CET; 21h ago
 Main PID: 1066 (npm)
   CGroup: /system.slice/mastodon-streaming.service
           ├─1066 npm                        
           ├─1579 sh -c node ./streaming/index.js
           ├─1580 node ./streaming/index.js
           └─1626 /usr/bin/node /home/mastodon/live/streaming/index.js

Jan 03 17:32:58 example.com systemd[1]: Started mastodon-streaming.
Jan 03 17:33:02 example.com npm[1066]: > mastodon@ start /home/mastodon/live
Jan 03 17:33:02 example.com npm[1066]: > node ./streaming/index.js
Jan 03 17:33:04 example.com npm[1066]: info Starting streaming API server master with 1 workers
Jan 03 17:33:04 example.com npm[1066]: info Starting worker 1
Jan 03 17:33:04 example.com npm[1066]: info Worker 1 now listening on 0.0.0.0:4000

● mastodon-sidekiq.service - mastodon-sidekiq
   Loaded: loaded (/etc/systemd/system/mastodon-sidekiq.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2018-01-03 17:32:58 CET; 21h ago
 Main PID: 1117 (bundle)
   CGroup: /system.slice/mastodon-sidekiq.service
           └─1117 sidekiq 5.0.5 live [0 of 5 busy]                                                                                          

Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:7
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:1
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:44:
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:38:
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:1
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:1
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:8
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:7
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:16:in 
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:25:in

Thanks for helping!


#4

Hello, yes you have errors but the information you provide is truncated. Some lines are missing and your output is too short to the right.


#5

Sorry! Here comes the complete output of journalctl -u mastodon-web.service:

and here again the output of systemctl status mastodon-*.service:

● mastodon-web.service - mastodon-web
   Loaded: loaded (/etc/systemd/system/mastodon-web.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2018-01-04 14:59:35 CET; 8min ago
 Main PID: 12249 (bundle)
   CGroup: /system.slice/mastodon-web.service
           ├─12249 puma 3.11.0 (tcp://0.0.0.0:3000) [live]                                                                                  
           ├─12273 puma: cluster worker 0: 12249 [live]                                                                                     
           └─12287 puma: cluster worker 1: 12249 [live]                                                                                     

Jan 04 15:03:56 example.com bundle[12249]: : SELECT  "session_activations".* FROM "session_activations" WHERE "session_activations"."session_id" IS NULL LIMIT $1' duration=57.77 view=0.00 db=12.32
Jan 04 15:03:56 example.com bundle[12249]: [9f35d098-9963-49c8-984f-2d57c0c97bb5]
Jan 04 15:03:56 example.com bundle[12249]: [9f35d098-9963-49c8-984f-2d57c0c97bb5] ActiveRecord::StatementInvalid (PG::UndefinedTable: ERROR:  relation "session_activations" does not exist
Jan 04 15:03:56 example.com bundle[12249]: LINE 1: SELECT  "session_activations".* FROM "session_activations" W...
Jan 04 15:03:56 example.com bundle[12249]:                                              ^
Jan 04 15:03:56 example.com bundle[12249]: : SELECT  "session_activations".* FROM "session_activations" WHERE "session_activations"."session_id" IS NULL LIMIT $1):
Jan 04 15:03:56 example.com bundle[12249]: [9f35d098-9963-49c8-984f-2d57c0c97bb5]
Jan 04 15:03:56 example.com bundle[12249]: [9f35d098-9963-49c8-984f-2d57c0c97bb5] app/controllers/application_controller.rb:83:in `current_session'
Jan 04 15:03:56 example.com bundle[12249]: [9f35d098-9963-49c8-984f-2d57c0c97bb5] app/controllers/about_controller.rb:35:in `initial_state_params'
Jan 04 15:03:56 example.com bundle[12249]: [9f35d098-9963-49c8-984f-2d57c0c97bb5] app/controllers/about_controller.rb:8:in `show'

● mastodon-streaming.service - mastodon-streaming
   Loaded: loaded (/etc/systemd/system/mastodon-streaming.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2018-01-03 17:32:58 CET; 21h ago
 Main PID: 1066 (npm)
   CGroup: /system.slice/mastodon-streaming.service
           ├─1066 npm                        
           ├─1579 sh -c node ./streaming/index.js
           ├─1580 node ./streaming/index.js
           └─1626 /usr/bin/node /home/mastodon/live/streaming/index.js

Jan 03 17:32:58 example.com systemd[1]: Started mastodon-streaming.
Jan 03 17:33:02 example.com npm[1066]: > mastodon@ start /home/mastodon/live
Jan 03 17:33:02 example.com npm[1066]: > node ./streaming/index.js
Jan 03 17:33:04 example.com npm[1066]: info Starting streaming API server master with 1 workers
Jan 03 17:33:04 example.com npm[1066]: info Starting worker 1
Jan 03 17:33:04 example.com npm[1066]: info Worker 1 now listening on 0.0.0.0:4000

● mastodon-sidekiq.service - mastodon-sidekiq
   Loaded: loaded (/etc/systemd/system/mastodon-sidekiq.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2018-01-03 17:32:58 CET; 21h ago
 Main PID: 1117 (bundle)
   CGroup: /system.slice/mastodon-sidekiq.service
           └─1117 sidekiq 5.0.5 live [0 of 5 busy]                                                                                                                     

Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:72:in `global'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:129:in `block in dispatch'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:44:in `with_context'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:38:in `with_job_hash_context'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:128:in `dispatch'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:168:in `process'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:85:in `process_one'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:73:in `run'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:16:in `watchdog'
Jan 04 13:58:57 example.com bundle[1117]: /home/mastodon/live/vendor/bundle/ruby/2.4.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:25:in `block in safe_thread'

#6

I cannot even copy out of your document… but clearly there is an error about missing database table.
Either you have forgotten to setup your database, or you didn’t run database migrations after upgrade.


#7

Mh. As mentioned it has been a fresh install. I’ve tried to follow the update tutorial. And this helped. The instance is running. Thanks for helping!