Synapse application logs sometimes log HTTP status codes as text.

[lampholder]

event_creator1.log-20200228 at 2020-02-28 00:45:13,117 - synapse.access.http.8095 the HTTP status code appears as HTTPStatus.FORBIDDEN instead of 403.

[erikjohnston]

This was a POST /_matrix/client/r0/rooms/:room_id/leave request

[anoadragon453]

Is this perhaps due to this line:

synapse/synapse/api/errors.py

Line 241 in d907e8f

super(AuthError, self).__init__(*args, **kwargs)

Where it's not passing arguments to SynapseError correctly?

[richvdh]

what do you mean? how is it not passing arguments correctly?

[anoadragon453]

@richvdh Ah, I had a brain fart and forgot how **kwargs worked.

I've been able to reproduce this by trying to log in as a deactivated user. Log line:

2020-03-31 16:21:10,130 - synapse.access.http.8008 - 281 - INFO - POST-237 - 127.0.0.1 - 8008 - {None} Processed request: 0.005sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.001sec/2) 76B HTTPStatus.FORBIDDEN "POST /_matrix/client/r0/login HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64; rv:76.0) Gecko/20100101 Firefox/76.0" [0 dbevts]

Looks like it's caused by this line:

synapse/synapse/api/errors.py

Line 190 in e8e2ddb

code=http_client.FORBIDDEN, msg=msg, errcode=Codes.USER_DEACTIVATED

Which hands SynapseError an http_client.FORBIDDEN instead of a simple 403. Changing this line to use a simple 403 instead returns the same line to the client, but produces the correct log line:

2020-03-31 16:23:21,907 - synapse.access.http.8008 - 281 - INFO - POST-8 - 127.0.0.1 - 8008 - {None} Processed request: 0.004sec/0.000sec (0.000sec, 0.001sec) (0.001sec/0.001sec/2) 76B 403 "POST /_matrix/client/r0/login HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64; rv:76.0) Gecko/20100101 Firefox/76.0" [0 dbevts]

So a PR to find/replace all instances of http_client.FORBIDDEN inbound.

[anoadragon453]

Actually a better solution might be to have the logger correctly and consistently print these objects, as there's lots of instances of http_client.* and there's not much to prevent us accidentally using these again in the future.

[anoadragon453]

Fixed by #7188