Hello,
Sorry if this is an obvious question. On Plausible self hosted we try to help everyone who is setting up their installation. But when they get an error from the app and we ask them to send logs, usually there’s not much info in the logs.
Looks like Phoenix turns a raised exception into a 500 response and happily moves on. But, the actual error is not logged which makes it difficult to understand what’s going on. Here’s a crash log from one of our users:
plausible_1 | 09:05:44.123 request_id=FnVflzPSw1Vu5p4AAAhj [info] POST /activate/request-code
plausible_1 | 09:05:44.124 request_id=FnVflzPSw1Vu5p4AAAhj [debug] Processing with PlausibleWeb.AuthController.request_activation_code/2
plausible_1 | Parameters: %{"_csrf_token" => "HDFscwE3G1sLdCMCeyASbVRFPCQPBxIiqD5BiFS5qMaw4eb4y7HomkUw", "_method" => "post"}
plausible_1 | Pipelines: [:browser]
plausible_1 | 09:05:44.131 request_id=FnVflzPSw1Vu5p4AAAhj [debug] QUERY OK source="users" db=5.7ms queue=0.2ms idle=1740.5ms
plausible_1 | SELECT u0."id", u0."email", u0."password_hash", u0."name", u0."last_seen", u0."trial_expiry_date", u0."theme", u0."email_verified", u0."inserted_at", u0."updated_at" FROM "users" AS u0 WHERE (u0."id" = $1) [1]
plausible_1 | 09:05:44.136 request_id=FnVflzPSw1Vu5p4AAAhj [debug] QUERY OK source="subscriptions" db=4.3ms idle=1746.4ms
plausible_1 | SELECT s0."id", s0."paddle_subscription_id", s0."paddle_plan_id", s0."update_url", s0."cancel_url", s0."status", s0."next_bill_amount", s0."next_bill_date", s0."user_id", s0."inserted_at", s0."updated_at", s0."user_id" FROM "subscriptions" AS s0 WHERE (s0."user_id" = $1) ORDER BY s0."inserted_at" DESC [1]
plausible_1 | 09:05:44.146 request_id=FnVflzPSw1Vu5p4AAAhj [debug] QUERY OK source="email_verification_codes" db=8.1ms queue=1.8ms idle=759.7ms
plausible_1 | UPDATE "email_verification_codes" AS e0 SET "user_id" = $1 WHERE (e0."user_id" = $2) [nil, 1]
plausible_1 | 09:05:44.150 request_id=FnVflzPSw1Vu5p4AAAhj [debug] QUERY OK source="email_verification_codes" db=1.8ms queue=1.7ms idle=760.9ms
plausible_1 | SELECT e0."code" FROM "email_verification_codes" AS e0 WHERE (e0."user_id" IS NULL) LIMIT 1 []
plausible_1 | 09:05:44.163 request_id=FnVflzPSw1Vu5p4AAAhj [debug] QUERY OK source="email_verification_codes" db=10.7ms queue=1.7ms idle=762.9ms
plausible_1 | UPDATE "email_verification_codes" AS e0 SET "user_id" = $1, "issued_at" = $2 WHERE (e0."code" = $3) [1, ~U[2021-04-13 09:05:44.150565Z], 2848]
plausible_1 | 09:05:44.164 request_id=FnVflzPSw1Vu5p4AAAhj [debug] Sending email with Bamboo.SMTPAdapter:
plausible_1 |
plausible_1 | %Bamboo.Email{assigns: %{code: 2848, user: %Plausible.Auth.User{__meta__: #Ecto.Schema.Metadata<:loaded, "users">, email: "<snip>", email_verified: true, google_auth: #Ecto.Association.NotLoaded<association :google_auth is not loaded>, id: 1, inserted_at: ~N[2021-04-13 04:12:38], last_seen: ~N[2021-04-13 08:23:08], name: "<snip>", password: nil, password_confirmation: nil, password_hash: "<snip>", site_memberships: #Ecto.Association.NotLoaded<association :site_memberships is not loaded>, sites: #Ecto.Association.NotLoaded<association :sites is not loaded>, subscription: nil, theme: "system", trial_expiry_date: ~D[2121-04-13], updated_at: ~N[2021-04-13 08:36:18]}}, attachments: [], bcc: [], cc: [], from: {nil, "\"<snip>\""}, headers: %{}, html_body: "Hey <snip>,\n<br /><br />\nEnter 2848 to verify your email address. This code will expire in 4 hours.\n", private: %{html_layout: false, message_params: %{"TrackOpens" => false}, tag: "activation-email", text_layout: false, view_module: PlausibleWeb.EmailView, view_template: "activation_email.html"}, subject: "2848 is your Plausible email verification code", text_body: nil, to: [{"<snip>", "<snip>"}]}
plausible_1 |
plausible_1 | 09:05:44.166 request_id=FnVflzPSw1Vu5p4AAAhj [warn] Failed to send Sentry event.Cannot send Sentry event because of invalid DSN
plausible_1 | 09:05:44.168 request_id=FnVflzPSw1Vu5p4AAAhj [warn] Failed to send Sentry event.Cannot send Sentry event because of invalid DSN
plausible_1 | 09:05:44.168 request_id=FnVflzPSw1Vu5p4AAAhj [info] Sent 500 in 44ms
plausible_1 | 09:05:44.168 request_id=FnVflzPSw1Vu5p4AAAhj [debug] Converted error ArgumentError to 500 response
plausible_1 | 09:05:44.170 request_id=FnVflzPSw1Vu5p4AAAhj [warn] Failed to send Sentry event.Cannot send Sentry event because of invalid DSN
It would be super helpful to get a full log of the ArgumentError that happened here. Anyone know how that achieve that?
