Implement events logging feature #1256

alessio · 2015-06-26T13:49:28Z

Record events (i.e. pluginhook's calls) as syslog entries and provide a shortcut command to display the last part of the log file.

A brief list of changes follows:

dokku:

New DOKKU_EVENTS_LOGFILE envvar to hold logfile location.

plugins/20_events/commands:

events output log entries, a tail's follow-like mode is provided too.
events:[on|off] enables/disables logging.
events:list lists events that are logged.

plugins/20_events/hook:

Generic hook that writes log entries. All the events are registered via symlink to this script.

plugins/common/functions:

dokku_log_event() writes log entries via logger.
dokku_log_pluginhook_call() formats log entries and writes them via dokku_log_event().

Record events (i.e. pluginhook's calls) as syslog entries and provide a shortcut command to display the last part of the log file. A brief summary of the changes follows: dokku: - New DOKKU_EVENTS_LOGFILE envvar to hold logfile location. plugins/20_events/commands: - events output log entries, a tail's follow-like mode is provided too. - events:[on|off] enables/disables logging. - events:list lists events that are logged. plugins/20_events/hook: - Generic hook that writes log entries. All the events are registered via symlink to this script. plugins/common/functions: - dokku_log_event() writes log entries via logger. - dokku_log_pluginhook_call() formats log entries and writes them via dokku_log_event().

It had gone lost while porting the original 3rd party plugin.

This should fix ShellCheck SC2046 error.

michaelshobbs · 2015-06-26T16:12:19Z

I have a few questions about this feature in general.

I'm not clear on the benefit of this plugin. Can you include the intended use-case?
Why do we think this belongs in the core plugin set?

Can you include an excerpt from the logs to show what this looks like?

michaelshobbs · 2015-06-26T16:19:03Z

plugins/20_events/commands

What does this do and why? Also can we have it output some sort of message if a user attempts dokku events and the plugin is not enabled?

Currently this happens

root@dokku:~/dokku# dokku plugins-install root@dokku:~/dokku# dokku events find: cannot search `': No such file or directory

In fact this happens on deployment as well

remote: find: cannot search `': No such file or directory remote: find: cannot search `': No such file or directory remote: find: cannot search `': No such file or directory

michaelshobbs · 2015-06-26T16:44:02Z

Just tested this. I don't see anything in /var/log/dokku.log but I do see this in /var/log/syslog:

Jun 26 16:41:03 dokku dokku[12857]: INVOKED: pre-delete( node-js-app )
Jun 26 16:41:13 dokku dokku[12996]: INVOKED: post-delete( node-js-app )
Jun 26 16:41:15 dokku dokku[13126]: INVOKED: receive-app( node-js-app a836400724f1c8aa34e6f873039621053ad6a639 )
Jun 26 16:41:17 dokku dokku[13478]: INVOKED: pre-build-buildstep( node-js-app )
Jun 26 16:41:17 dokku dokku[13491]: INVOKED: docker-args-build( node-js-app )
Jun 26 16:41:33 dokku dokku[13772]: INVOKED: post-build-buildstep( node-js-app )
Jun 26 16:41:33 dokku dokku[13811]: INVOKED: pre-release-buildstep( node-js-app )
Jun 26 16:41:33 dokku dokku[13887]: INVOKED: post-release-buildstep( node-js-app )
Jun 26 16:41:33 dokku dokku[13922]: INVOKED: pre-deploy( node-js-app )
Jun 26 16:41:33 dokku dokku[14046]: INVOKED: docker-args-deploy( node-js-app )
Jun 26 16:41:34 dokku dokku[14100]: INVOKED: bind-external-ip( node-js-app )
Jun 26 16:41:34 dokku dokku[14185]: INVOKED: check-deploy( node-js-app 9050d85117a547bce73b5ac91dac075029ece28355a68f80315587581af650cd web 5000 172.17.0.43 )
Jun 26 16:41:44 dokku dokku[14253]: INVOKED: post-deploy( node-js-app 5000 172.17.0.43 )
Jun 26 16:41:44 dokku dokku[14316]: INVOKED: nginx-hostname( node-js-app node-js-app dokku.me )
Jun 26 16:41:44 dokku dokku[14373]: INVOKED: nginx-pre-reload( node-js-app )

I did run dokku plugins-install before testing.

michaelshobbs · 2015-06-26T16:46:00Z

plugins/20_events/commands

lint fails.

In ./plugins/20_events/commands line 31: logged="$(find $(dirname $0) -type l -printf '%f ' | sort)" ^-- SC2046: Quote this to prevent word splitting.

alessio · 2015-06-26T16:52:29Z

(The discussion begun on IRC, so I'm mostly copying here what I said in #dokku)

We experienced kernel hangs on containers removal and this has proven to be very helpful to understand which were the events that triggered the issue.

To answer both questions, the rationale is to mitigate the lack of logging functionalities in dokku by providing a not too fine-grained view of what's going on behind the scenes.

alessio · 2015-06-26T17:44:37Z

@michaelshobbs can you please check whether /etc/rsyslog.d/99-dokku.conf was created?

michaelshobbs · 2015-06-26T18:23:54Z

@alessio indeed

root@dokku:~/dokku# cat /etc/rsyslog.d/99-dokku.conf
:syslogtag, contains, "dokku" /var/log/dokku.log

alessio · 2015-06-26T19:53:41Z

@michaelshobbs run:

ls -l /var/log/dokku.log

Please confirm that your result matches the following

$ ls -l /var/log/dokku.log 
-rw-rw-r-- 1 syslog dokku 171986 Jun 26 20:30 /var/log/dokku.log

It's crucial that the owner is syslog, otherwise rsyslog can't write to it.
It should be enough to reload rsyslog (and the install should be doing that), though I'd suggest to stop the service and start it again:

sudo service rsyslog restart

michaelshobbs · 2015-06-27T03:46:12Z

Restarting rsyslog seems to work. Can we add that to the install script?

Seems that a mere reload doesn't work.

alessio · 2015-06-27T09:21:51Z

Done.

josegonzalez · 2015-06-27T16:56:23Z

Can you add logrotation for this?

alessio · 2015-06-28T00:16:55Z

Definitely we can. I'll work on it.

sent via mobile
On 27 Jun 2015 17:56, "Jose Diaz-Gonzalez" notifications@github.com wrote:

Can you add logrotation for this?

—
Reply to this email directly or view it on GitHub
#1256 (comment).

@josegonzalez

As requested by @josegonzalez.

alessio · 2015-06-28T22:36:50Z

I was wondering whether it would be a good idea to create a /var/log/dokku/ sub-dir and redirect the plugin's logs to its own /var/log/dokku/events.log as we may want to log other things in the future. Comments are much welcome!

michaelshobbs · 2015-06-30T16:28:29Z

@alessio looks like there's an issue with your test

not ok 25 (events) check conffiles
# (in test file tests/unit/events.bats, line 22)
#   `stats -c '%U:%G:%a' /var/log/dokku.log' failed with status 127
# Creating my-cool-guy-test-app... done
# output: 
# status: 
# /home/ubuntu/dokku/tests/unit/test_helper.bash: line 17: [: : integer expression expected
# output: 
# status: 
# /home/ubuntu/dokku/tests/unit/test_helper.bash: line 17: [: : integer expression expected
# /tmp/bats.53387.src: line 22: stats: command not found

Parse output and check return code after running test commands with the 'run' utility.

michaelshobbs · 2015-07-01T16:43:17Z

@alessio since we're now log rotating, i think a /var/log/dokku/ directory makes sense.

alessio · 2015-07-01T16:46:52Z

Indeed it does

Rename dokku.log to events.log. Refresh tests accordingly.

michaelshobbs · 2015-07-01T17:50:15Z

plugins/20_events/hook

This question may be naive, but any reason we're doing a double negative here. More directly why not do this?

[[ "$DOKKU_EVENTS" ]] && dokku_log_pluginhook_call "$(basename $0)" "$@"

EDIT: This would also be consistent with plugins/20_events/install.

On Wed, Jul 1, 2015 at 6:50 PM, Michael Hobbs notifications@github.com wrote:

This question may be naive, but any reason we're doing a double negative here. More directly why not do this?

It's just my personal preference, but if that breaks the code style
I'm more than happy to fix it then.

Alessio Treglia | www.alessiotreglia.com
Debian Developer | alessio@debian.org
Ubuntu Core Developer | quadrispro@ubuntu.com
0416 0004 A827 6E40 BB98 90FB E8A4 8AE5 311D 765A

Well, actually due set -e if $DOKKU_EVENTS is unset the hook would return 1, and that would break the plugins chain, wouldn't it?

This is mostly for consistency with its own install script.

This reverts commit 54ed3c1.

michaelshobbs · 2015-07-01T18:48:34Z

I was wrong, you were right here. pipefail strikes again!! Can we make them both double negative for consistency?

alessio · 2015-07-01T18:54:54Z

Done, it's all yours now!

michaelshobbs · 2015-07-01T19:05:08Z

👍

Implement events logging feature

michaelshobbs · 2015-07-01T23:21:55Z

@alessio I hit you up on IRC but just in case, would you be willing to add some documentation around this?

alessio · 2015-07-02T07:20:56Z

👍 sure, I will write some docs ASAP

Alessio Treglia added 6 commits June 26, 2015 14:47

Fix missing 'fi' in plugins/20_events/install

e9a7344

Add missing DOKKU_RSYSLOG_FILTER in install script

f5e213e

It had gone lost while porting the original 3rd party plugin.

Double quote $@ array expansions

a858bc8

Double quote $@ in plugins/20_events/install too

8e79161

Quote `find' statement to prevent word splitting

466670d

This should fix ShellCheck SC2046 error.

michaelshobbs reviewed Jun 26, 2015
View reviewed changes

Alessio Treglia added 2 commits June 26, 2015 17:57

Get rid of cruft leftover

da3b00a

Attempt to fix SC2046

fb5d3a0

Restart rsyslog once installed

16e4001

Seems that a mere reload doesn't work.

Handle log rotation

69aba06

As requested by @josegonzalez.

Add small test suite for events logging

b380bde

Alessio Treglia and others added 3 commits June 30, 2015 17:34

Fix horrible typo

b24e782

Attempt to fix circleci build failure

efc55bd

Parse output and check return code after running test commands with the 'run' utility.

Fix test case expected output

1d4b9a1

alessio added 2 commits July 1, 2015 17:50

Merge branch 'master' into pr-dokku-events

172e71c

Create dokku's /var/log/dokku/ private namespace

91c691a

Rename dokku.log to events.log. Refresh tests accordingly.

michaelshobbs reviewed Jul 1, 2015
View reviewed changes

alessio added 3 commits July 1, 2015 19:20

Fix double negative statement

54ed3c1

This is mostly for consistency with its own install script.

Revert "Fix double negative statement"

89d1aca

This reverts commit 54ed3c1.

Use d-neg condition to prevent unexpected failures

0ed0201

michaelshobbs added a commit that referenced this pull request Jul 1, 2015

Merge pull request #1256 from alessio/pr-dokku-events

2698ce6

Implement events logging feature

michaelshobbs merged commit 2698ce6 into dokku:master Jul 1, 2015

Uh oh!

Implement events logging feature #1256

Implement events logging feature #1256

Uh oh!

Conversation

alessio commented Jun 26, 2015

Uh oh!

michaelshobbs commented Jun 26, 2015

Uh oh!

michaelshobbs Jun 26, 2015

Choose a reason for hiding this comment

Uh oh!

michaelshobbs Jun 26, 2015

Choose a reason for hiding this comment

Uh oh!

michaelshobbs commented Jun 26, 2015

Uh oh!

michaelshobbs Jun 26, 2015

Choose a reason for hiding this comment

Uh oh!

alessio commented Jun 26, 2015

Uh oh!

alessio commented Jun 26, 2015

Uh oh!

michaelshobbs commented Jun 26, 2015

Uh oh!

alessio commented Jun 26, 2015

Uh oh!

michaelshobbs commented Jun 27, 2015

Uh oh!

alessio commented Jun 27, 2015

Uh oh!

josegonzalez commented Jun 27, 2015

Uh oh!

alessio commented Jun 28, 2015

Uh oh!

alessio commented Jun 28, 2015

Uh oh!

michaelshobbs commented Jun 30, 2015

Uh oh!

michaelshobbs commented Jul 1, 2015

Uh oh!

alessio commented Jul 1, 2015

Uh oh!

michaelshobbs Jul 1, 2015

Choose a reason for hiding this comment

Uh oh!

alessio Jul 1, 2015

Choose a reason for hiding this comment

Uh oh!

alessio Jul 1, 2015

Choose a reason for hiding this comment

Uh oh!

michaelshobbs Jul 1, 2015

Choose a reason for hiding this comment

Uh oh!

michaelshobbs commented Jul 1, 2015

Uh oh!

alessio commented Jul 1, 2015

Uh oh!

michaelshobbs commented Jul 1, 2015

Uh oh!

michaelshobbs commented Jul 1, 2015

Uh oh!

alessio commented Jul 2, 2015

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants