paganotoni
commented
4 years ago @Baggerone this one is related with the buffalo-pop middleware. Moving the issue there.
Closed Baggerone closed 1 year ago
paganotoni
commented
4 years ago @Baggerone this one is related with the buffalo-pop middleware. Moving the issue there.
github-actions[bot]
commented
2 years ago This issue is stale because it has been open 30 days with no activity. Remove stale label or comment. Otherwise, this will be closed in 7 days.
sio4
commented
2 years ago It seems like this issue is similar to gobuffalo/buffalo#2300 (fixed by gobuffalo/buffalo#2334). The current behavior is something like the following:
When the controller returns an error:
DEBU[2022-10-07T18:30:56+09:00] --- BEGIN Transaction ---
DEBU[2022-10-07T18:30:56+09:00] --- ROLLBACK Transaction ---
ERRO[2022-10-07T18:30:56+09:00] error db=0s params="{}" request_id=4e89496142495081b778-f69bc8ba256445c0378a status=500 tx=kzCInTjmJdEMCQbFJgMRVtQZajRSwf
INFO[2022-10-07T18:30:56+09:00] /error/ db=0s duration=2.661444ms human_size="33 kB" method=GET params="{}" path=/error/ request_id=4e89496142495081b778-f69bc8ba256445c0378a size=33238 status=500 tx=kzCInTjmJdEMCQbFJgMRVtQZajRSwfWhen the controller panic:
DEBU[2022-10-07T18:31:00+09:00] --- BEGIN Transaction ---
DEBU[2022-10-07T18:31:00+09:00] --- ROLLBACK Transaction (inner function panic) ---
ERRO[2022-10-07T18:31:00+09:00] transaction was rolled back due to inner panic db=0s params="{}" request_id=369b41b1362d1bc00d67-1c9cebe15cfc759723b3 status=500 tx=uElIJBJRGMvJNrIsgPlpBFwSjHxrWD
INFO[2022-10-07T18:31:00+09:00] /panic/ db=0s duration=2.622052ms human_size="33 kB" method=GET params="{}" path=/panic/ request_id=369b41b1362d1bc00d67-1c9cebe15cfc759723b3 size=33279 status=500 tx=uElIJBJRGMvJNrIsgPlpBFwSjHxrWDWhen the controller returns nil:
DEBU[2022-10-07T18:31:26+09:00] --- BEGIN Transaction ---
DEBU[2022-10-07T18:31:26+09:00] --- ROLLBACK Transaction ---
INFO[2022-10-07T18:31:26+09:00] /nil/ db=0s duration=1.74566ms human_size="0 B" method=GET params="{}" path=/nil/ request_id=50ca8a5db3d08a343e0b-6df8283bcc90cabaa373 size=0 status=0 tx=DINSOaTngPPNAJYfvZWZkhRwgrdevBAll of them end with rollback, and the first two cases will put two lines of logs. Access log in INFO, and ERROR log.
The case of nil is somewhat tricky, but still, there is a log line with status=0 which could be interpreted as an error. I would like to address this case in the near future but not a higher priority.
sio4
commented
1 year ago Finally, the implementation is that Buffalo's hidden middleware will log it when the status code was not set but the handler returns nil. This log is Debug level since it could be verbose in the production if a user still wants to use this behavior though.
Description
Logging improvement request. There seems to be no log that indicates that a buffalo handler returned a nil error without first calling c.Render() with a 200-300 response code.
This would be very helpful when using transactions, so that there is an indication of why the transaction is rolled back despite no error being triggered in the code.
(I ignorantly wasted several hours trying to troubleshoot my situation.)
Steps to Reproduce the Problem
app.Use(popmw.Transaction(models.DB))return nilExpected Behavior
A log to say that the transaction was cancelled because nil was returned from the handler without c.Render(200...) being called first.
Actual Behavior
The database will not include the entry that was supposed to have been created, but the logs will have no warning or error to tell you that the transaction was cancelled.
Info
Please run
buffalo infoand paste the information below where it says "PASTE_HERE".