Hi everyone, I am trying to retrieve logs from prefect server. For a single flow run I am seeing log messages print out of order. They are being printed in timestamp order (and I’ve verified the wrongly ordered lines do not have the exact same timestamp). I am guessing the timestamps are created on the server? Is there any way to embed a sequence number in the log messages or a local timestamp from the agent, or do I have to put something in the log message itself? Thanks.

It’s actually generated from your Flow compute and uploaded. Could you show me an example so I can get a better picture?

I can’t copy all the code, but maybe I can copy some pieces of it. I’ll have to check. But it’s basically a more complicated version of:

logger("Line1")
logger("Line2")

and the log is

Line2
Line1

What executor are you using?

dask

With an actual cluster?

I’m not sure actually, I haven’t set any of that up. I don’t think it’s using a cluster, we’re just using it for local execution so we can gate the flows. But these timestamps are all from a single flow, if it’s all from a local clock shouldn’t that not matter?

Ah well I’m asking because if you have a Dask cluster, you shouldn’t even get worker logs by default so you would have needed to have some kind of service ship the logs somehow so I was wondering if you had something like this. But also so I can test to try to replicate

Hmm maybe we have some logging config I haven’t seen yet. I’ll have to look into it more, thanks.

Out timestamp in the backend goes to milliseconds so I can’t think of a reason why they’d be out of order. I don’t really have enough to go off over. Would you be able to DM me some logs?

I can probably send you something, thanks

I can’t think of anything because the UI renders the logs separate from what the Flow is sending so you can’t really change the logging format

Sorry, this is in our own UI. I’m asking if there is any easy way to include sequence data in the log messages so that I can get the right order through graphql.

I understand. Do you mean you are not using the Prefect UI? Or do you mean Prefect UI but you host it?

We don’t use the prefect UI for log viewing, for a number of reasons. Our UI is totally separate from prefect UI, prefect is just a backend service.

Actually sorry I take that back. The issue is how the logs are stored with Prefect.

{
        "id": "fc715146-435b-4ff3-96f8-cec1dc017a67",
        "message": "Task 'test[1]': Finished task run for task with final state: 'Failed'",
        "timestamp": "2021-12-14T20:16:06.028796+00:00",
        "name": "prefect.CloudTaskRunner"
      },

I don’t see a place you can stick an identifier unless it’s in the message

To be more clear, “we” (i.e. the developers of our system) use the prefect UI all the time, but our end users (who need to view logs) do not

Ah i see

Yeah I didn’t think so, but if you look in the api docs there’s lots more fields in the log message type and I don’t know what many of them do. So I figured I’d ask before I hacked my own implementation 🙂

I did take a look but really not seeing anything to help honestly

To clarify further, this is for a build system. We routinely have ~5000 line logs. There is a 2500 line cutoff for your gql, and you can only see a few lines at a time, so the prefect UI isn’t really suitable.

I’ll leave a message with our engineers to see if we can utilize

info

or

object_id

to hold metadata. Will get back to you when i get a response

Ah yes I wanted to ask about

info

. The prefect cli doesn’t use this correctly (or maybe I’m on an old version). prefect cli seems to think

info

is a bool, but in the current api it has a parameter. Whatever that does it may be useful to us. The prodcut I’m working on is a software build system, so logs are very important.

object_id

 is the object id associated with a log, use for audit log tracking. 

info

 appears to be an arbitrary json blob with some additional information about the log.