Hi everyone, I am trying to retrieve logs from pre...
# prefect-server
d
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.
k
It’s actually generated from your Flow compute and uploaded. Could you show me an example so I can get a better picture?
d
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:
Copy code
logger("Line1")
logger("Line2")
and the log is
Copy code
Line2
Line1
unfortunately the real log is many thousands of lines long
k
What executor are you using?
d
dask
k
With an actual cluster?
d
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?
k
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
d
Hmm maybe we have some logging config I haven’t seen yet. I’ll have to look into it more, thanks.
No cluster, dask running a single instance on the same machine as the agent
k
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?
d
I can probably send you something, thanks
Actually I think it is because of identical timestamps, I must have misinterpreted. At least the one I just found has identical timestamps, and I would expect it to cause this problem. Is there any way to embed extra info in the records, without adding it to the message itself?
k
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
d
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 can of course encode it into the log message, I’d rather not do that unless it’s the only way
k
I understand. Do you mean you are not using the Prefect UI? Or do you mean Prefect UI but you host it?
d
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.
k
Actually sorry I take that back. The issue is how the logs are stored with Prefect.
Copy code
{
        "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
d
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
k
Ah i see
d
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 🙂
k
I did take a look but really not seeing anything to help honestly
d
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.
k
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
d
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.
Sorry not a bool, but it didn’t have parameters.
k
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.
So no there is no way to embed some other metadata