Swap puts calls for logger calls throughout

harry-wood commented 6 years ago

Give more control over output by moving it all to loggers

Tackling https://github.com/feedreader/pluto/issues/4

harry-wood commented 6 years ago

I didn't quite succeed in making it run "quiet". Where do these messages about merging the template get put out?

pluto --quiet build
activerecord-utils/0.4.0 (activerecord/5.1.4) on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
activityutils/0.1.1 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
[info] pluto/1.2.3 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
Merging template pack 'blank'
  Loading template manifest /home/ubuntu/.pluto/blank/blank.txt...
  Merging to planet.html...
  Loading template (from file) >/home/ubuntu/.pluto/blank/blank.html.erb<...
  Merging to planet.cards.html...
  Loading template (from file) >/home/ubuntu/.pluto/blank/blank.cards.html.erb<...
  Copying to css/blank.css from /home/ubuntu/.pluto/blank/css/blank.css...
  Copying to css/blank.cards.css from /home/ubuntu/.pluto/blank/css/blank.cards.css...
  Copying to css/font-awesome.css from /home/ubuntu/.pluto/blank/css/font-awesome.css...
  Copying to i/feed-icon-10x10.png from /home/ubuntu/.pluto/blank/i/feed-icon-10x10.png...
  Copying to i/view-headlines.png from /home/ubuntu/.pluto/blank/i/view-headlines.png...
  Copying to i/view-snippets.png from /home/ubuntu/.pluto/blank/i/view-snippets.png...
  Copying to i/view-standard.png from /home/ubuntu/.pluto/blank/i/view-standard.png...
  Copying to js/jquery-2.0.3.min.js from /home/ubuntu/.pluto/blank/js/jquery-2.0.3.min.js...
  Copying to js/blank.js from /home/ubuntu/.pluto/blank/js/blank.js...
  Copying to font/fontawesome-webfont.eot from /home/ubuntu/.pluto/blank/font/fontawesome-webfont.eot...
  Copying to font/fontawesome-webfont.svg from /home/ubuntu/.pluto/blank/font/fontawesome-webfont.svg...
  Copying to font/fontawesome-webfont.ttf from /home/ubuntu/.pluto/blank/font/fontawesome-webfont.ttf...
  Copying to font/fontawesome-webfont.woff from /home/ubuntu/.pluto/blank/font/fontawesome-webfont.woff...
  Copying to font/FontAwesome.otf from /home/ubuntu/.pluto/blank/font/FontAwesome.otf...
Done (in 0.43715411 s).

geraldb commented 6 years ago

@harry-wood Again first thanks for your time & effort. Sorry to say that is the trouble with rubocops e.g. the rule to remove all puts e.g.:

  # say hello
  puts PlutoFeedFetcher.banner   if $DEBUG || (defined?($RUBYLIBS_DEBUG) && $RUBYLIBS_DEBUG)

The print banner is already conditional - no need to use logger.info. Others include printing the system info or listing all installed templates if you call pluto list or pluto about - you expect output it's conditional on a command :-)

Sorry but about half the puts are ok and do NOT output debug / progress info. Sorry it's my error - logging is a "cross-cutting concern" e.g. it's all over the place.

The merging is in the pakman - template package manager and merger - library / gem https://github.com/rubylibs/pakman Since the quiet functionality is so important to you I will try to update it this week.

harry-wood commented 6 years ago

No no. I didn't use rubocop at all for this transition. This was good old-fashioned coding by hand :-)

half the puts are ok and do NOT output debug / progress info

hmm ok. So one of my starting assumptions here, is that it would be better to use logger everywhere rather than puts. I think this is general best practice, and actually here we have a perfect example of why. We want to be able to increase/decrease the messages sent to stdout. i.e. we want log levels.

There's some subtlety in what we might mean by that, and how we assign log levels to certain messages. I've tried to think about that as I went through them all.

debug - for the messages which help you understand internals of how pluto is working, perhaps if you're also looking at the pluto code.
info - for general messages saying what pluto is doing. Useful from the perspective of somebody using/configuring pluto e.g. listing out the sites it's fetching as it does this.
warn - for things which might be problem, but do not cause pluto to stop running. Included within this are the cases where pluto hits upon an error while fetching a particular feed (The warning might well mention the word 'error'. That's OK) This is the interesting log level for our use with OpenStreetMap's long list of blogs. We'd like to run pluto without really seeing all the activity as it fetches all these blogs on each run, but we're interested in any problems fetching a particular blog (Sound about right @tomhughes ?)
error - Is for things which cause pluto to give up and stop running e.g. missing config parameters.

You're saying some messages "do NOT output debug / progress info". In this context you'd be talking about info, warn, and error level messages.

One thing I'm not so sure about is whether it's a good idea for 'quiet' to set the log level to 'warn'. Maybe it should be more quiet than that ('error'), but then we'd need another arg for the level we're wanting.

geraldb commented 6 years ago

@harry-wood Again super happy that you care about making pluto better and that it runs openstreetmaps blogs. Will try to push out / upload a new pluto gem later today (sunday nov/26).

One thing I'm not so sure about is whether it's a good idea for 'quiet' to set the log level to 'warn'. Maybe it should be more quiet than that ('error'), but then we'd need another arg for the level we're wanting.

Good point. I'd say no worries. Let's make it (one more) option eg. --q1 and --q2 or --warn or --error. I'm a fan of the "ruby (perl) philosphy" e.g. there are many ways to do it (TAMWTDI ) . Just need to find out what might be the most "natural" way / option. My current thinking is lets make --error and -q and --quiet synonyms (aliases) and --warn a new option/flag (maybe with a -w alias).

Update: Adding these new flags for now:

desc 'Only show errors and fatal messages'
switch [:q, :quiet, :err, :error], negatable: false

desc 'Only show warnings, errors and fatal messages'
switch [:w, :warn], negatable: false

Update To answer you question:

You're saying some messages "do NOT output debug / progress info". In this context you'd be talking about info, warn, and error level messages.

Sorry for the confusion was just saying that if you use

 $ pluto list

to list all templates than you always want output, thus, this gets always output with puts - same is for

 $ pluto about

again. No worries. You're right usually logger is the way to go. Again happy to work through so we get the level of detail right. Thanks for your patience.

geraldb commented 6 years ago

@harry-wood I uploaded two new gems that is, pluto itself and pluto-feedfetcher. If you can try out the update that would be great e.g.:

 $ gem install pluto                ## should install v1.3.0
 $ gem install pluto-feedfetcher    ## should install v 0.1.1

Now you can use the --quiet/-q/--error or --warn flags e.g. pluto --quiet build planet.ini

Would be great if you could post the beginning of the console output (when running with --quiet) so the messages still getting printed out can get cleaned up later this week. I will (try to) work through some more pluto-xxx libraries tomorrow (Monday). Thanks again for getting it started. Cheers. Prost.

harry-wood commented 6 years ago

Ah yes. I see what you mean about pluto list and pluto about. These are commands where the only point of running it is the output. I hadn't thought of that.

Cool looks like your changes have made --quiet a bit quieter. I think we'd most likely want to run it with --warn actually (which currently looks the same). Here's how it looks for my test config with two feeds:

$ pluto --warn update planet.ini
activerecord-utils/0.4.0 (activerecord/5.1.4) on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
activityutils/0.1.1 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
pluto/1.3.0 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
db settings:
{:adapter=>"sqlite3", :database=>"./planet.db"}
Updating feed subscription >osm_blog< - >https://blog.openstreetmap.org/feed/<...
Updating feed subscription >osm_diaries< - >http://www.openstreetmap.org/diary/rss<...
Done.

I'm not seeing the 'merge template' message. But I'm not exactly sure when that happens. Maybe you've stopped it outputting that somehow? So that's good.

Also if I delete the planet.db then I see a lot of ** NEW lines. I think ideally at the warn level it wouldn't output any of that, and also not the "Updating feed subscription" line. Nothing per feed. Just messages about blogs which are unreachable, is what we're hoping for I think.

geraldb commented 6 years ago

@harry-wood Great thanks for update.

Cool looks like your changes have made --quiet and bit quieter. I think we'd most likely want to run it with --warn actually (which currently looks the same).

Will change the default wasn't sure - that is - making --quiet an alias for --warn and for just errros and up let's make it --err or --error or --quieter

Here's how it looks for my test config with two feeds:

$ pluto --warn update planet.ini

The update command will only update (fetch) the feeds. The build command does everything e.g. $ pluto --warn build planet.ini and the merge command just merges the templates.

Also will add the auto-adding (if missing) planet.ini back (was too much simplifing) so that $ pluto --warn update works again. Thanks again for trying it out and getting it all stared. Will update the gems later today.

geraldb commented 6 years ago

@harry-wood Thanks for the wait. I uploaded new gems, that is, if you update:

$ gem install pakman           # now v1.1.0
$ gem install pluto-models  # now v1.5.0
$ gem install pluto               # now v1.3.1

As preferred --quiet/-q now maps to --warn and (--quieter maps to --err) and the default planet.ini arg is back e.g. try:

$ pluto -q build        ## will auto-add (again) the missing planet.ini

Let me know if you still get some output in quiet mode

harry-wood commented 6 years ago

I took the latest code again. Ah yeah, doing build rather than update triggers the merging template messages, which are still quite chatty

$ pluto -q build
activerecord-utils/0.4.0 (activerecord/5.1.4) on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
activityutils/0.1.1 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
pluto/1.3.1 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
Merging template pack 'blank'
  Loading template manifest /home/ubuntu/.pluto/blank/blank.txt...
  Merging to planet.html...
  Loading template (from file) >/home/ubuntu/.pluto/blank/blank.html.erb<...
  Merging to planet.cards.html...
  Loading template (from file) >/home/ubuntu/.pluto/blank/blank.cards.html.erb<...
  Copying to css/blank.css from /home/ubuntu/.pluto/blank/css/blank.css...
  Copying to css/blank.cards.css from /home/ubuntu/.pluto/blank/css/blank.cards.css...
  Copying to css/font-awesome.css from /home/ubuntu/.pluto/blank/css/font-awesome.css...
  Copying to i/feed-icon-10x10.png from /home/ubuntu/.pluto/blank/i/feed-icon-10x10.png...
  Copying to i/view-headlines.png from /home/ubuntu/.pluto/blank/i/view-headlines.png...
  Copying to i/view-snippets.png from /home/ubuntu/.pluto/blank/i/view-snippets.png...
  Copying to i/view-standard.png from /home/ubuntu/.pluto/blank/i/view-standard.png...
  Copying to js/jquery-2.0.3.min.js from /home/ubuntu/.pluto/blank/js/jquery-2.0.3.min.js...
  Copying to js/blank.js from /home/ubuntu/.pluto/blank/js/blank.js...
  Copying to font/fontawesome-webfont.eot from /home/ubuntu/.pluto/blank/font/fontawesome-webfont.eot...
  Copying to font/fontawesome-webfont.svg from /home/ubuntu/.pluto/blank/font/fontawesome-webfont.svg...
  Copying to font/fontawesome-webfont.ttf from /home/ubuntu/.pluto/blank/font/fontawesome-webfont.ttf...
  Copying to font/fontawesome-webfont.woff from /home/ubuntu/.pluto/blank/font/fontawesome-webfont.woff...
  Copying to font/FontAwesome.otf from /home/ubuntu/.pluto/blank/font/FontAwesome.otf...
Done (in 0.50638139 s).
Done.

...but other than merging templates (which only happens once at least), or if I run pluto update, it's looking nice and quiet

geraldb commented 6 years ago

@harry-wood First thanks for your patience and ongoing saga.

merging template messages, which are still quite chatty

That's an easy fix. Please make sure you have the latest (and greatest) pakman library / gem e.g.

$ gem install pakman     # must be version v1.1.0+

Can you retry? (Note: To see what version of pakaman you're using - it should be listed when you type $ pluto about ) I found some more messages output by the strip_ads in feedfilter - will try to add the logger later today. Cheers.

harry-wood commented 6 years ago

Ah sorry yes. I was rebuilding all this repo's code, but reinstalling pakman did the trick

$ pluto -q build
activerecord-utils/0.4.0 (activerecord/5.1.4) on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
activityutils/0.1.1 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
pluto/1.3.1 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
Done.

harry-wood commented 6 years ago

obviously we can close this PR.

Maybe I'll look at tidying the output for failing feeds at some point

harry-wood commented 6 years ago

Well maybe it's OK as is actually. I was imagining failing feeds should count as warnings, and then there should be fewer other warnings. However being errors as they are, the --quiet command output is pretty good (for our long list of osm feeds, some of which are failing) :

$ pluto -q build
activerecord-utils/0.4.0 (activerecord/5.1.4) on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
activityutils/0.1.1 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
pluto/1.3.1 on Ruby 2.3.1 (2016-04-26) [x86_64-linux-gnu]
*** error - fetch HTTP - 404 Not Found
[error] *** error: fetching feed 'igor_brejc' - HTTP status 404 Not Found
*** error - fetch HTTP - 404 Not Found
[error] *** error: fetching feed 'gary_gale' - HTTP status 404 Not Found
*** error - fetch HTTP - 404 Not Found
[error] *** error: fetching feed 'tom_hughes' - HTTP status 404 Not Found
Done.

geraldb commented 6 years ago

I'd say error might be the better category for 404 not found - if you start from zero you will get some missing feed id warnings that get filtered out when just printing errors. Was thinking about downgrading the missing feed guids warnings to debug - but if you're fine with error than I'd say let's keep the warnings about missing feed guids. Thanks for getting it started and testing. You're contributions are always welcome. Keep it up. PS: Will try to work trough some minor libraries later today / this week (feedfilter, activerecord-utils, etc.). PPS: As written on the original ticket / issue - one (easy) way to never miss errors is adding a (simple) errors.log template to the planet template pack e.g. errors.log.erb (and than loop / output over all errors - they get stored in the database).

feedreader / pluto

Swap puts calls for logger calls throughout #12