I'm facing a weird issue with the Discord bot (based on

shuttle-poise = "0.14.0"

) that I'm building. It works fine locally with

cargo shuttle run

, but I can't get it to start up properly with

cargo shuttle deploy

. I've tried restarting the project (

cargo shuttle project restart --idle-minutes 0

) for good measure. The output I get looks like this:

2023-04-22T08:37:56.573958676Z  INFO     Finished release [optimized] target(s) in 32.80s
2023-04-22T08:37:56.584035103Z  INFO      Running unittests src/main.rs (opt/shuttle/shuttle-builds/dls-bot/target/release/deps/dls_bot-65a0a031568fb4aa)

2023-04-22T08:37:56.654605339Z  INFO Entering built state

2023-04-22T08:37:56.654806880Z  INFO Entering loading state
2023-04-22T08:37:56.659518514Z TRACE shuttle_deployer::runtime_manager: making new client
2023-04-22T08:37:56.663949621Z DEBUG shuttle_deployer::runtime_manager: Starting alpha runtime at: /opt/shuttle/shuttle-executables/ac9b1280-3b1e-48c3-88b5-d65808fa2789
2023-04-22T08:37:58.667368290Z  INFO shuttle_proto::runtime: connecting runtime client
2023-04-22T08:37:58.667464780Z DEBUG hyper::client::connect::http: connecting to 127.0.0.1:21644
2023-04-22T08:37:58.670419758Z DEBUG hyper::client::connect::http: connected to 127.0.0.1:21644
2023-04-22T08:37:58.673072001Z DEBUG {service.ready=true} tower::buffer::worker: processing request
2023-04-22T08:37:58.675968159Z  INFO shuttle_deployer::deployment::run: loading project from: /opt/shuttle/shuttle-executables/ac9b1280-3b1e-48c3-88b5-d65808fa2789
2023-04-22T08:37:58.677593420Z DEBUG shuttle_deployer::deployment::run: loading service
2023-04-22T08:37:58.679686726Z DEBUG {service.ready=true} tower::buffer::worker: processing request
Deployment has not entered the running state

I don't see any error message, or any output from my application, including the

tracing::info!

line at the very beginning of my

shuttle_service::main

. Any tips on how to debug this further? (The bot uses Secrets and Postgres.)

Hey there, the shuttle runtime already uses a logger - if you are trying to set up your own logger currently it doesn't work out of the box. If this doesn't fix your problem is there any chance you have a public repo link so we could take a closer look at this?

Sorry, I wasn't clear -- this isn't a logging problem as far as I can tell, and I'm not currently trying to customise the logger (just running the vanilla

shuttle_service::main

setup). Note the last line in the output ("Deployment has not entered the running state") -- as far as I can tell control never passes to my main function.

Hmmmm what about if you try using

cargo shuttle project rm

then

cargo shuttle project restart --idle-minutes 0

?

let me give it a shot

Oh sorry, yeah. Brainfart 😂

sure -- pretty sure it showed as

stopped

, but I'll post the output once it's done building in the restarted project

just realised I haven't upgraded my cargo shuttle

with the last log line being

2023-04-22T09:11:29.116858387Z DEBUG shuttle_deployer::deployment::run: loading service

Do the commands get registered when you try to run it locally?

yes

I'm assuming all of your shuttle-related deps are also

0.14.0

right?

yes -- at least that's the intention, let me check the

Cargo.lock

Do you have a github repo link so I can investigate this further?

Sorry, not really -- there's some non-public info in the repo

Ah 😅 I'll refer this to engineering then, hopefully oddgrd or someone will be able to look into this since if it's just not deploying but runs locally this is a bit of a problem

Thanks, really appreciate the engagement on a weekend!

No worries, this is my personal Discord account (as well as the account I use for being on here) so I don't mind too much 😅

@red-quill-28140 can you query the deployment log directly? IE check the deployment list for the ID, then pass that to

cargo shuttle logs

?

@enough-oil-62271 Huh, fascinating. There's an extra log line shown by `cargo shuttle logs`:

2023-04-22T09:11:29.118926415Z DEBUG {service.ready=true} tower::buffer::worker: processing request

possibly yeah

"loading"

definitely unusual. Is the code you're using available to look at anywhere?

No, sorry

the main function and its attributes would be a good place to start aye

double check the deployment list to be sure it's stopped and isn't still trying to run

shows as stopped

aight, good, see if a fresh deploy gets anywhere 🤞🏼

Build in progress 🤞

while we're here I should probably let you know you can set dev-only secrets using

Secrets.dev.toml

😂 I realise this is totally unrelated but it'll stop you needing to use cfg

Huh, and that's picked up if debug assertions are on?

I think it's picked up for local builds only, unsure about debug assertions or not?

If you're trying to run your app locally and

Secrets.dev.toml

exists, it'll use that file first for secrets

Hmm, I'm confused about this. I thought in production the Shuttle secret store is used anyway, and

Secrets.toml

is the mechanism for local runs. When would I have both

Secrets.toml

and

Secrets.dev.toml

?

Ah sorry I think I confused you, let me reclarify - the

Secrets.dev.toml

file is normally for when you want two separate environments for your secrets

Ooh, deployment crash: https://pastebin.com/M6tAAUqd

ah god it's one of these

any more details in the logs query it suggests to run?

cargo shuttle logs

doesn't show substantially more -- it just has these extra lines:

2023-04-22T13:46:30.452806100Z  INFO Entering crashed state
2023-04-22T13:46:30.455388149Z ERROR {error="Load error: <no panic message>"} shuttle_deployer::deployment::run: service startup encountered an error

lmao

<no panic message>

okay yeah that definitely looks like something the Shuttle folks will have to give a look for ya, not sure what to do with that 🤣

what type are you using for your pg connection?

Ah, reading https://docs.shuttle.rs/resources/shuttle-secrets again made it click. Indeed I want to use

Secrets.dev.toml

, thanks for the tip!

the random number array leads to one of the resources being broken

@agreeable-painting-48846 ok, you're right about resources being the issue -- if I comment out the injected

#[shuttle_shared_db::Postgres]

parameter, the crash does not happen

are you using SQLx for the pool connection?

yes

hmmmm, what about if you try using PgPool as the type?

trying

I'm guessing it will probably break your web service but pgpool always works for me

I don't really expect a difference, given its definition:

/// An alias for [`Pool`][crate::pool::Pool], specialized for Postgres.
pub type PgPool = crate::pool::Pool<Postgres>;

Hmmmm, yeah I guess In any case, hopefully engi will be up this weekend to help 😅 if not, unfortunately it might have to wait a bit

Lemme have a look at my own postgres related code, maybe there's a difference somewhere...

For the record: Changing the type to

PgPool

resulted in the same hang. (Not sure why sometimes it hangs and sometimes it crashes with those numbers in the message... 🤔 )

The only thing you have different here it seems is you're using the migrations macro, whereas my code has it just including a single schema file 🤔

I thought as much, I just wanted to rule it out in case

@agreeable-painting-48846 @enough-oil-62271 So, this comment triggered something in the back of my mind, and after confirming that removing the migrations allows the bot to start up I think I've got the resolution. Here's my summary: - Root cause: A migration was failing against the Shuttle-supplied Postgres instance. This meant bot startup was failing abruptly. - Aggravating factors: - Originally I was doing

.expect(...)

on the migrations, which would abort the process if they fail, and seemingly not flush log buffers in the process. This made it impossible to diagnose, as additional logging I added was just not being captured. - Even switching to

?

(returning an

Err

from the

shuttle_service::main

function) still seemed to not produce all log messages that it should have; there may be some flushes missing. - Operational misunderstanding: I thought deleting and recreating the Shuttle project would discard the database and start from a fresh one; that's why I never considered migrations could be a problem. Might be worth documenting how long databases live (and perhaps provide commands for managing them? I'd quite like to be able to discard the database without connecting to the

postgres://

URI)

Yeah I was also surprised (pleasantly, in my case) that restarting the project doesn't discard the DB. Glad you were able to get it working! Agreed that there are definitely improvements for logging failure states that need to happen :/