[WIP] [Console] Add basic support for automatic console exception logging #19382

jameshalsall · 2016-07-18T18:17:56Z

Q	A
Branch?	master
Bug fix?	no
New feature?	yes
BC breaks?	no
Deprecations?	no
Tests pass?	yes (still to write tests for new feature)
Fixed tickets	#10895
License	MIT
Doc PR	(TO DO)

This is a quick initial concept for automatic exception logging, it currently takes the 2 listeners outlined in the docs (http://symfony.com/doc/current/cookbook/console/logging.html) and brings them into the standard edition.

I'd like to get some feedback before writing tests and updating the docs in a separate PR.

TODO:

Confirm messaging
Write tests
Update docs in separate PR
Prevent console errors from writing to stderr

jameshalsall · 2016-07-20T19:58:44Z

ping @Tobion - be good to get your feedback on this before I do any more

nicolas-grekas · 2016-07-21T07:02:20Z

src/Symfony/Component/Console/EventListener/ExceptionListener.php

+            $event->setExitCode(255);
+        }
+
+        $message = sprintf('Command `%s` exited with status code %d');


this looks something else than what the title of this PR suggests. moreover, I'm not sure it's forth logging a non zero status code: it's the command's responsibility to know if it's worth logging of not, don't you think?

The idea of this PR is to add automatic exception logging "out of the box" with zero configuration. Maybe I'm misunderstanding but surely anything other than a 0 exit code would result in some kind of log entry, unless there's a fatal PHP error before Symfony kernel bootstraps

something is missing in the sprintf

I would add the current argument/options

jameshalsall · 2016-07-21T20:13:23Z

After thinking about this a little more, I still can't help but think this is not a good idea:

Console exceptions are handled by the Logger service and written to stdout by default
When the user passes verbosity flags to the command, e.g. -vvv, they would expect that this information is still written to stdout
I don't think it offers much value to have an exception listener by default that writes to var/log folder when they would be written to stdout as well

I was against this originally in #10895, but thought it might offer some value for people. Now I'm not so sure.

Curious to see what @Tobion thinks as he was the Symfony member who originally was for this change.

lyrixx · 2016-08-09T13:39:29Z

src/Symfony/Component/Console/EventListener/ExceptionListener.php

+
+        $message = sprintf('Command `%s` exited with status code %d');
+
+        $this->logger->warning($message);


I would put error.

lyrixx · 2016-08-09T13:39:59Z

👍
(We have the same code in one of our internal repository)

lyrixx · 2016-08-09T13:41:28Z

src/Symfony/Component/Console/EventListener/ExceptionListener.php

+        }
+
+        if ($exitCode > 255) {
+            $event->setExitCode(255);


IMHO, this should not be done here.
And BTW, it's already done there https://github.com/symfony/symfony/blob/master/src/Symfony/Component/Console/Application.php#L141-L147

Great point, I will remove this

nicolas-grekas · 2016-08-09T19:06:00Z

src/Symfony/Component/Console/EventListener/ExceptionListener.php

+            $exitCode
+        );
+
+        $this->logger->error(


We prefer single line here, same above. And in fact I think the intermediate $message is not required.

👍 my bad

lyrixx · 2016-08-17T16:07:21Z

src/Symfony/Component/Console/EventListener/ExceptionListener.php

-        $this->logger->error('Command `{command}` exited with status code {code}', array('command' => implode(' ', $_SERVER['argv']), 'code' => $exitCode));
+        $input = new ArgvInput(null, $event->getCommand()->getDefinition());
+
+        $this->logger->error('Command `{command}` exited with status code {code}', array('command' => (string) $input, 'code' => $exitCode));


Do we really need the backtick ?

Probably not, I'll remove them

lyrixx · 2016-08-18T09:29:30Z

src/Symfony/Component/Console/EventListener/ExceptionListener.php

+
+        $exception = $event->getException();
+
+        $this->logger->error($exception->getMessage(), array('exception' => $exception));


I'm sorry to be very picky, but the log message is not good. I prefer something like that:
'Exception thrown while running command: "%s". Message: "%s".

It's better because if the RDBMS goes down (for example), many commands or consumers will fail. So you will receive N time the exact same message. It's better to have N messages because all commands are different and you must know what command fail.

No problem, I'll update this later

lyrixx · 2016-08-19T08:42:26Z

src/Symfony/Component/Console/composer.json

@@ -23,7 +23,8 @@
        "symfony/event-dispatcher": "~2.8|~3.0",
        "symfony/filesystem": "~2.8|~3.0",
        "symfony/process": "~2.8|~3.0",
-        "psr/log": "~1.0"
+        "psr/log": "~1.0",
+        "phpunit/phpunit": "~4.0"


We never add phpunit dependency in symfony.

Not sure why that's showing, I reverted that change last night - was committed by mistake

Yeah, I saw that after commenting. Thanks.

fabpot · 2016-09-14T21:54:51Z

@jameshalsall What's the status of this PR?

jameshalsall · 2016-09-14T22:11:19Z

I will finish this off soon :)

James Halsall

Sent from
https://polymail.io/

On Wed, 14 Sep 2016 at 22:55 Fabien Potencier

<
mailto:Fabien Potencier notifications@github.com

wrote:

a, pre, code, a:link, body { word-wrap: break-word !important; }

https://github.com/jameshalsall
What's the status of this PR?

—

You are receiving this because you were mentioned.

Reply to this email directly,
#19382 (comment)
, or
https://github.com/notifications/unsubscribe-auth/AAeg3Hf0DrRtq-6gSJR7pksk02gbyXRMks5qqG1IgaJpZM4JO_W1
.

chalasr · 2016-11-06T15:56:11Z

It would be great to see this happen.

jameshalsall · 2016-11-06T17:19:39Z

I'll pick this up again this week, had forgotten about it.

chalasr · 2017-01-15T14:42:03Z

Finished in #21003, thanks @jameshalsall

fabpot · 2017-01-15T16:21:21Z

Closing in favor of #21003

…eshalsall, chalasr) This PR was merged into the 3.3-dev branch. Discussion ---------- [Console][FrameworkBundle] Log console exceptions | Q | A | ------------- | --- | Branch? | master | Bug fix? | no | New feature? | yes | BC breaks? | no | Deprecations? | no | Tests pass? | yes | Fixed tickets | #10895 | License | MIT | Doc PR | symfony/symfony-docs#7373 Continues #19382, fixing some issues including: - ability to display the input string for any `InputInterface` implementation (cast to string if possible, use the command name otherwise) - if the input can be casted as string, cleanup the result (from `command "'command:name' --foo=bar" ` to `command "command:name --foo=bar"`) - made `ExceptionLister::$logger` private instead of protected - changed methods name from `onKernel*` to `onConsole*` (e.g. `onConsoleException`) and removed unnecessary doc blocks - Added more tests Log for an exception: > [2016-12-22 00:34:42] app.ERROR: Exception thrown while running command: "cache:clear -vvv". Message: "An error occured!" {"exception":"[object] (RuntimeException(code: 0): An error occured! at /Volumes/HD/Sites/tests/sf-demo-3.2/vendor/symfony/symfony/src/Symfony/Bundle/FrameworkBundle/Command/CacheClearCommand.php:61)","command":"cache:clear -vvv","message":"An error occured!"} [] Commits ------- 919041c Add Console ExceptionListener 9896547 Add basic support for automatic console exception logging

haroldiedema · 2017-08-04T14:49:29Z

Exit codes are used to communicate with the processes that spawned a process (e.g symfony command). In our case, we use exit codes to communicate back to bash processes to indicate what a spawned process did.

Now our 'error'-logs are being spammed for no reason since exit code 3 is NOT an error.

In short: An exit code other than 0 isn't necessarily an error. This commit makes the assumption that it is.

chalasr · 2017-08-05T11:41:41Z

@haroldiedema Would you mind to open a PR for changing the log level?

carsonbot added Status: Needs Review Feature labels Jul 18, 2016

nicolas-grekas reviewed Jul 21, 2016
View reviewed changes

jameshalsall changed the title ~~Add basic support for automatic console exception logging~~ [WIP] [Console] Add basic support for automatic console exception logging Jul 30, 2016

lyrixx reviewed Aug 9, 2016
View reviewed changes

jameshalsall force-pushed the automatic-console-exception-logging branch from 6382bf1 to 6acd944 Compare August 9, 2016 18:57

nicolas-grekas reviewed Aug 9, 2016
View reviewed changes

jameshalsall and others added 9 commits August 17, 2016 16:45

Add basic support for automatic console exception logging

4284161

Fix coding standards

17ef8db

Simplify the log entry for console exceptions

3d6b22b

Remove unnecessary exit code handling in ExceptionListener

0961f8c

Fix onKernelTerminate message logging

5bd799e

Fix coding style

80c3ac3

Fix code style

f7a7048

Fix code style, add TODO

c21d206

Update console error log with placeholders and context

2874431

jameshalsall force-pushed the automatic-console-exception-logging branch from b8209e7 to 2874431 Compare August 17, 2016 15:47

Replace global usage with ArgvInput

bcbc8cb

lyrixx reviewed Aug 17, 2016
View reviewed changes

jameshalsall added 2 commits August 17, 2016 20:15

Remove backticks around command name in log message

da278e6

Add test for onKernelTerminate

44a0822

lyrixx reviewed Aug 18, 2016
View reviewed changes

Update console ExceptionListener messaging, add test

5dc8b61

jameshalsall added 2 commits August 18, 2016 19:41

Add tests for onKernelTerminate, fix log message

b196557

Revert change to composer.json

e6c4994

lyrixx reviewed Aug 19, 2016
View reviewed changes

javiereguiluz added this to the 3.3 milestone Nov 7, 2016

chalasr mentioned this pull request Dec 20, 2016

[Console][FrameworkBundle] Log console exceptions #21003

Merged

fabpot closed this Jan 15, 2017

nicolas-grekas modified the milestones: 3.x, 3.3 Mar 24, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[WIP] [Console] Add basic support for automatic console exception logging #19382

[WIP] [Console] Add basic support for automatic console exception logging #19382

jameshalsall commented Jul 18, 2016 •

edited

Loading

jameshalsall commented Jul 20, 2016

nicolas-grekas Jul 21, 2016

jameshalsall Jul 21, 2016

lyrixx Aug 9, 2016

jameshalsall Aug 9, 2016

jameshalsall commented Jul 21, 2016

lyrixx Aug 9, 2016

lyrixx commented Aug 9, 2016

lyrixx Aug 9, 2016

jameshalsall Aug 9, 2016

nicolas-grekas Aug 9, 2016

jameshalsall Aug 9, 2016

lyrixx Aug 17, 2016

jameshalsall Aug 17, 2016

lyrixx Aug 18, 2016

jameshalsall Aug 18, 2016

lyrixx Aug 19, 2016

jameshalsall Aug 19, 2016

lyrixx Aug 19, 2016

fabpot commented Sep 14, 2016

jameshalsall commented Sep 14, 2016

chalasr commented Nov 6, 2016

jameshalsall commented Nov 6, 2016

chalasr commented Jan 15, 2017

fabpot commented Jan 15, 2017

haroldiedema commented Aug 4, 2017

chalasr commented Aug 5, 2017


		$message = sprintf('Command `%s` exited with status code %d');

		$this->logger->warning($message);


		$exception = $event->getException();

		$this->logger->error($exception->getMessage(), array('exception' => $exception));

[WIP] [Console] Add basic support for automatic console exception logging #19382

[WIP] [Console] Add basic support for automatic console exception logging #19382

Conversation

jameshalsall commented Jul 18, 2016 • edited Loading

jameshalsall commented Jul 20, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jameshalsall commented Jul 21, 2016

Choose a reason for hiding this comment

lyrixx commented Aug 9, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

fabpot commented Sep 14, 2016

jameshalsall commented Sep 14, 2016

chalasr commented Nov 6, 2016

jameshalsall commented Nov 6, 2016

chalasr commented Jan 15, 2017

fabpot commented Jan 15, 2017

haroldiedema commented Aug 4, 2017

chalasr commented Aug 5, 2017

jameshalsall commented Jul 18, 2016 •

edited

Loading