hey <@U01UBDC4E1L> <@UU43XA551> I'm working on rem...
# flyte-deployment
k
hey @Guillaume Perchais @Babis Kiosidis I'm working on removing redundant logs for authenticated flyteadmin requests. If we just had this would that work okay at spotify?
y
side question, do you know where this log line is coming from?
and if you do know, do you think the email could be added easily?
k
@Yee it's from here: https://github.com/flyteorg/flyteadmin/blob/master/pkg/rpc/adminservice/project.go#L58 which i'm considering deleting in favor of the interceptor
oh actually, it looks like the function caller is using UserID https://github.com/flyteorg/flyteadmin/blob/master/auth/interfaces/context.go#L61 but i'm not sure that's actually the email
looks like the UserInfo has it though, so i can modify it in my PR if that's helpful
y
yes please
if it’s easy to do
1
b
Hey we don't rely on these logs so no hard needs from our side. Here are some logs and how they look like for us right now Is this the first log line ?
Copy code
{
  "data": {
    "src": "handlers.go:199"
  },
  "message": "Found existing metadata Bearer .....",
  "severity": "DEBUG",
  "timestamp": "2022-03-15T08:21:58Z"
}
Copy code
{
  "data": {
    "src": "handlers.go:227"
  },
  "message": "Running authentication gRPC interceptor",
  "severity": "DEBUG",
  "timestamp": "2022-03-15T08:21:58Z"
}
Nothing is printed on the UserID part in the log below (?)
Copy code
{
  "data": {
    "src": "handlers.go:183"
  },
  "message": "gRPC server info in logging interceptor [] method [/flyteidl.service.AdminService/CreateExecution]\n",
  "severity": "DEBUG",
  "timestamp": "2022-03..."
}
This looks a bit verbose, difficult to look at.
Copy code
{
  "data": {
    "src": "log.go:91"
  },
  "message": "Recording request: [{\"Principal\":{\"Subject\":\"\",\"ClientID\":\"\",\"TokenIssuedAt\":\"2022-03-15T08:21:55Z\"},\"Client\":{\"ClientIP\":\"...\"},\"Request\":{\"Method\":\"CreateNodeEvent\",\"Parameters\":{\"domain\":\"production\",\"name\":\"...\",\"node_id\":\"...\",\"project\":\"...\"},\"Mode\":1,\"ReceivedAt\":\"2022-03-15T08:21:58.270480136Z\"},\"Response\":{\"ResponseCode\":\"OK\",\"SentAt\":\"2022-03-15T08:21:58.304569484Z\"}}]",
  "severity": "INFO",
  "timestamp": "2022-03-15T08:21:58Z"
}
Also it's good to mention that thes logs are noisy and we notice that these 4 logs keep repeating over and over. It's difficult to notice other logs. So reducing them makes sense 👍
1
k
thanks for confirming @Babis Kiosidis I just checked in the changes to remove that last log. the user id should be coming from the authenticated context. cc @Yee would you know why it could be empty?
y
not sure but it’s going away right? is it there in the interceptor log?
k
it's empty in the interceptor log too
gRPC server info in logging interceptor [] method
y
and authentication is turned on?
that’s a dumb question, but the logging middleware sits after the authentication middleware, so if there is no token, it should’ve been rejected.
and it never should’ve reached the log statement.
can we file a bug for this and I can look in the future, it’s been a while since I’ve played around with this so my local debugging isn’t set up.
and by authentication turned on i mean - if you use flytectl, it pops open a web browser?
b
ah i think we do the token exchange with the authz server but maybe we dont use an identity token between flyteadmin and our proxy/service
Were these changes merged [for the reduced logging]?
k
yup! should be in flyteadmin release v0.6.114
b
I see thanks!
163 Views