These are chat archives for ManageIQ/manageiq/performance

20th
Nov 2015
Joe Rafaniello
@jrafanie
Nov 20 2015 01:14
@kbrock clearly, it's been a while since you read audit log messages
Jason Frey
@Fryguy
Nov 20 2015 01:18
You don't read them, per se. :smirk:
Keenan Brock
@kbrock
Nov 20 2015 03:47
I understand. you want me to understand what it is like to try and understand extermely verbose input
:shoe: on other :foot:
Oleg Barenboim
@chessbyte
Nov 20 2015 14:34
@kbrock complaining is only 10% of a solution. the 90% is offering a worthwhile solution. ;-)
that came out like something Yogi Berra would have said
LOL
Keenan Brock
@kbrock
Nov 20 2015 14:35
20% is thinking up the solution, 70% is finding a way to offer it in a meaningful way
I sure wish my pain threshold were higher. :(
Oleg Barenboim
@chessbyte
Nov 20 2015 14:39
so, there are historical reasons for why the evm.log is the way it is - thanks in no small part to Tom Hennessy
going forward, we may consider using modern tools to slice and dice the log, which may lead us to a different log format and clearer content
Alex Krzos
@akrzos
Nov 20 2015 14:43
:+1: to common logging
Oleg Barenboim
@chessbyte
Nov 20 2015 14:45
@akrzos saw sliver of Kibana demo yesterday - pretty impressive
Keenan Brock
@kbrock
Nov 20 2015 15:03
@chessbyte We are sometimes logging 2-3 times for the same message.
e.g.: log that we are going to putting a request to delete 5 ids into the queue. Then we log the queue insert with those 5 ids.
Question: is Tom the best person for asking if we can get rid of the statement "inserting 5 ids into the queue", and just leaving the queue insert?
@chess 2: we have pages of log messages on startup for what seems like unneeded info. (varying seed statements) Would be nice to reduce that too. Who typically needs to debug startup? (is it a dev like jason, or gss like tom?)
Joe Rafaniello
@jrafanie
Nov 20 2015 15:05
@kbrock if you find specific seemingly useless log messages, open a PR/issue showing before/after and why you are thinking it's useless...
Keenan Brock
@kbrock
Nov 20 2015 15:06
@jrafanie thanks - that is small and actionable for me. and tangible/actionable for others. +1
Joe Rafaniello
@jrafanie
Nov 20 2015 15:06
let's look at specific areas individually and question their value independently
Keenan Brock
@kbrock
Nov 20 2015 15:06
(and it avoids a meeting about theoretical stuff)
Oleg Barenboim
@chessbyte
Nov 20 2015 15:06
@kbrock agree with @jrafanie -- let's focus on (small) continuous improvements
Joe Rafaniello
@jrafanie
Nov 20 2015 15:07
yes, exactly, I like tiny changes and questioning small things because you're more likely to have actionable items that can be tried and compared to see if it's good
it's useful to question the value of really old stuff, that's how we remove no longer needed cruft
Oleg Barenboim
@chessbyte
Nov 20 2015 15:08
@jrafanie you are an expert deleter
Joe Rafaniello
@jrafanie
Nov 20 2015 15:09
but to be clear, we usually tried to have bookend log messages around things in case they blew up or were slow
Keenan Brock
@kbrock
Nov 20 2015 15:09
no - that is good. it is the 1) "I'm going to" 2) "I am" and then 3) "I did" - I have trouble with #1 + #2
Joe Rafaniello
@jrafanie
Nov 20 2015 15:10
I don't know about expert... I do :heart: finding no longer needed code... less stuff for me to grok
Keenan Brock
@kbrock
Nov 20 2015 15:10
less stuff to grok
Alex Krzos
@akrzos
Nov 20 2015 15:10
@jrafanie I don't think that works well with the thought process behind common logging, It becomes very hard to "glue" log statements together from kibana
Keenan Brock
@kbrock
Nov 20 2015 15:10
less stuff to support
Joe Rafaniello
@jrafanie
Nov 20 2015 15:11
yeah, @akrzos I think we have to look at kibana/common logging differently... maybe even POC a tiny thing with logging specifically for kibana
or some other common logger thing
Keenan Brock
@kbrock
Nov 20 2015 15:11
influxdb = my logging virus
oops ... you guys now know my secret plan...
don't care about the end technology. but want to be able to look at events in a graph not text to know something is wrong
Alex Krzos
@akrzos
Nov 20 2015 15:12
:+1: influxdb
Joe Rafaniello
@jrafanie
Nov 20 2015 15:12
that way, we can determine how we get from "current logging" to "logging that is dissectable"
Oleg Barenboim
@chessbyte
Nov 20 2015 15:14
logging has 2 purposes - to measure (which I think Kibana is good at) and to help find bugs that customer is hitting
Matthew Draper
@matthewd
Nov 20 2015 15:14
I wonder whether the "I am going to" log could somehow live elsewhere
It stops being interesting pretty quickly, as soon as you're "going to" do something else
Feels like it could be some sort of short ring buffer, separate from the "stuff I have done", which you obviously want to keep for a later-investigation-suitable length of time
Oleg Barenboim
@chessbyte
Nov 20 2015 15:16
bookends are pretty important to narrow down where something is breaking
maybe code is so burned in that we no longer need them
Keenan Brock
@kbrock
Nov 20 2015 15:16
too bad there is no ^R in logging
not talking bookends
Oleg Barenboim
@chessbyte
Nov 20 2015 15:16
but I remember that saved our butts on numerous occasions in the startup days
Keenan Brock
@kbrock
Nov 20 2015 15:16
talking the double starting / double stating intention
Oleg Barenboim
@chessbyte
Nov 20 2015 15:17
yes - only 1 starting is needed
Matthew Draper
@matthewd
Nov 20 2015 15:17
I think I'm talking about the 'open' side of the bookends… at lower level, once they're closed uneventfully, the open seems unlikely to be interesting
Though you'd still want higher level indications
Keenan Brock
@kbrock
Nov 20 2015 15:18
  def self.delete_by_id(ids)
    ids = [ids].flatten
    _log.info("Queuing deletion of jobs with the following ids: #{ids.inspect}")
    MiqQueue.put(
      :class_name  => self.name,
      :method_name => "destroy",
      :priority    => MiqQueue::HIGH_PRIORITY,
      :args        => [ids],
      :zone        => MiqServer.my_zone
    )
  end
THAT log statement
Oleg Barenboim
@chessbyte
Nov 20 2015 15:19
should be removed :scissors:
Keenan Brock
@kbrock
Nov 20 2015 15:19
but I'm mixed. it is informational and in english
but the queue logs the same exact thing
ok
think I already have that pr, but I notice it is all about
example 2: seeds
do we really care what is updated / created?
Oleg Barenboim
@chessbyte
Nov 20 2015 15:21
the thinking was that seeding should only update/create things once and (almost) never again
Keenan Brock
@kbrock
Nov 20 2015 15:21
agreed
Joe Rafaniello
@jrafanie
Nov 20 2015 15:21
some seeds were notoriously slow and knowing what was done and how long was probably the goal
Keenan Brock
@kbrock
Nov 20 2015 15:21
but we sure have a lot of output from there - even on the common case
Oleg Barenboim
@chessbyte
Nov 20 2015 15:22
so, you will almost never see it in logs, unless there is a bug in the logging of update
Keenan Brock
@kbrock
Nov 20 2015 15:22
aah
if you have a bug, the logging is painful - then you fix it
Oleg Barenboim
@chessbyte
Nov 20 2015 15:23
if it is always logging "updated", then we have an issue
Keenan Brock
@kbrock
Nov 20 2015 15:23
can we change our upgrade process to run migrations AND seeds? and get rid of auto seeds?
@chessbyte +1 thanks
Joe Rafaniello
@jrafanie
Nov 20 2015 15:23
note, this PR is an example... product features were always updating existing rows because we had duplicate features with the same identifier, causing more logging: ManageIQ/manageiq#4581
Oleg Barenboim
@chessbyte
Nov 20 2015 15:23
@kbrock not sure of the implications
Keenan Brock
@kbrock
Nov 20 2015 15:24
@jrafanie that is beautiful
Oleg Barenboim
@chessbyte
Nov 20 2015 15:24
@kbrock we really need to review our upgrade "process"
Matthew Draper
@matthewd
Nov 20 2015 15:24
@kbrock didn't we recently discuss that?
.. with some enthusiasm, if I recall ;)
Keenan Brock
@kbrock
Nov 20 2015 15:24
@chessbyte first implication. I won't get to say primitive/primordial/premadona/p.... all the time. (this is a pro and a con)
ooh
I did prune it down
and speed it up
but I'm having trouble getting over the lock on all other records - all appliances block on all others for startup
and recently, I've been in the logs a lot more as I'm going over performance - and it is a tad bit painful
Matthew Draper
@matthewd
Nov 20 2015 15:25

I mean we specifically discussed:

can we change our upgrade process to run migrations AND seeds? and get rid of auto seeds?

(and the conclusion was "we should look into that")
Joe Rafaniello
@jrafanie
Nov 20 2015 15:26

but I'm having trouble getting over the lock on all other records - all appliances block on all others for startup

Is this a documented problem?

Keenan Brock
@kbrock
Nov 20 2015 15:26
@matthewd agreed. so we've put it in the back of our minds to let the solution percolate
+1
Joe Rafaniello
@jrafanie
Nov 20 2015 15:26
I don't know that we ever have appliances seeding at the same time
Keenan Brock
@kbrock
Nov 20 2015 15:26
@jrafanie we have appliances starting at the same time?
Joe Rafaniello
@jrafanie
Nov 20 2015 15:27
that's what you said... did you mean workers?
Keenan Brock
@kbrock
Nov 20 2015 15:27
and every one needs to make sure that the seeds are correct. and no 2 can do that at the same time
ooh
@jrafanie think so
you know what - I withdrawl. I'll wait until I have better data.
Joe Rafaniello
@jrafanie
Nov 20 2015 15:27
if you are concerned about startup... I think you may want to lobby for forking workers ;-)
Keenan Brock
@kbrock
Nov 20 2015 15:28
well, I'm lobbying for getting the responsibility of forking our process and workers out of vmdb. and into a gem / unicorn / runner / ...
Joe Rafaniello
@jrafanie
Nov 20 2015 15:28
all these silly processes fighting over IO to read the exact same ruby files
Keenan Brock
@kbrock
Nov 20 2015 15:29
but, I need more data. and that is just a complaint now
Joe Rafaniello
@jrafanie
Nov 20 2015 15:29

well, I'm lobbying for getting the responsibility of forking our process and workers out of vmdb. and into a gem / unicorn / runner / ...

IMHO, that's not a goal we can achieve in one step...

Keenan Brock
@kbrock
Nov 20 2015 15:29
+1
Oleg Barenboim
@chessbyte
Nov 20 2015 15:29
forking workers and our queue workers exiting more often may clear memory more efficiently without much of a performance penalty
Joe Rafaniello
@jrafanie
Nov 20 2015 15:29
getting to standard rails: eager/preload all the things is step one in my mind
Keenan Brock
@kbrock
Nov 20 2015 15:29
@jrafanie a threading statement? (At least in part?)
Joe Rafaniello
@jrafanie
Nov 20 2015 15:29
I can't stand the autoload bugs and the need for the sti loader thing
Keenan Brock
@kbrock
Nov 20 2015 15:30
omg. sorry @matthewd but I hate sti loader
Matthew Draper
@matthewd
Nov 20 2015 15:30
I'm reluctant to even aim for it, because I hope for at-least-some threading… which would put us in an awkward situation if we're suddenly sitting on a "generic" forker
@kbrock me too buddy, me too.
Jason Frey
@Fryguy
Nov 20 2015 15:30

I can't stand the autoload bugs and the need for the sti loader thing

This would still happen in dev and test though

Keenan Brock
@kbrock
Nov 20 2015 15:30
probably the fact that it has sti in the name doesn't help though. (all know I'm not a big fan of that in general)
Jason Frey
@Fryguy
Nov 20 2015 15:30
so eager load solves nothing for those envs
Matthew Draper
@matthewd
Nov 20 2015 15:31
confirm.
Keenan Brock
@kbrock
Nov 20 2015 15:31
all - thanks for the links to the issues with rails loader (think it was from @matthewd ) - very cool stuff
Joe Rafaniello
@jrafanie
Nov 20 2015 15:35

so eager load solves nothing for those envs

yeah, the real goal to do rails out of box eager load/autoload... there's no silver bullet but doing things different from default is only good if we have tangible benefits from it

Matthew Draper
@matthewd
Nov 20 2015 15:36
@jrafanie but rails out-of-box autoload is broken. that's what our sti loader fixes.
Joe Rafaniello
@jrafanie
Nov 20 2015 15:36
LOL :wink:
where were you @matthewd when Jose NACKED @Fryguy and I, RE eagerload ;-)
Jason Frey
@Fryguy
Nov 20 2015 15:39
OMG I remember that
Matthew Draper
@matthewd
Nov 20 2015 15:40
Sadly, there's nothing we can do to fix it upstream
STI loader is deep hax
Jason Frey
@Fryguy
Nov 20 2015 15:40
rails/rails#3148
@jrafanie :sparkles: memorieeees
Joe Rafaniello
@jrafanie
Nov 20 2015 15:42
nice