For awhile now lately, we have been seeing Elastic Search indexing
quickly fall behind as some log files generated in the gate have become
larger. Currently, we download a full log file into memory and then
emit it line-by-line to be received by a logstash listener. When log
files are large (example: 40M) logstash gets bogged down processing
them.
Instead of downloading full files into memory, we can stream the files
and emit their lines on-the-fly to try to alleviate load on the log
processor.
This:
* Replaces use of urllib2.urlopen with requests with stream=True
* Removes manual decoding of gzip and deflate compression
formats as these are decoded automatically by requests.iter_lines
* Removes unrelated unused imports
* Removes an unused arg 'retry' from the log retrieval method
Change-Id: I6d32036566834da75f3a73f2d086475ef3431165
Belts and suspenders for cases where content encoding may not be
present. I believe this is possible if the content is served with the
identity encoding. In that case setting the encoding header isn't
required.
Change-Id: If18670d4fd3656a35f818247539b7afad39493e6
Zuul gives us the source url to index. Previously we tried to fetch
url + .gz because in many cases we uploaded the file as a gzip file but
logically treated it as unzipped. Now with logs in swift we compress
files without the .gz suffix. This means we should be able to always
fetch the url that zuul provides unmodified.
Depends-On: https://review.opendev.org/678303
Change-Id: I0ea4d9daa905ccb50372b73b5035758fc0963716
The severity filters are passed the entire json event and not just a
string. Update the systemd filter to access the message string out of
the event json dict.
Prior to this we get a type error:
2019-08-19 17:18:48,055 Exception handling log event.
Traceback (most recent call last):
File "/usr/local/bin/log-gearman-worker.py", line 255, in
_handle_event
keep_line = f.process(out_event)
File "/usr/local/bin/log-gearman-worker.py", line 183, in process
m = self.SYSTEMDRE.match(msg)
TypeError: expected string or buffer
Change-Id: I7ab56ac397133f00539d9d3374fa400363ef12d6
Now that logs have moved into swift, the os-loganalyze middleware that
stripped DEBUG level logs when the URL was given a ?level= parameter
no longer functions.
We move to filtering DEBUG statements directly. Because services in
devstack now run as systemd services, their log files are actually
journalctl dumps. Thus we add a new filter for systemd style
timestamps and messages (this is loosely based on the zuul log viewer
at [1]).
[1] 8c1f4e9d6b/web/src/actions/logfile.js
Change-Id: I54087c95c809612758139136d5b3e86b1a6372be
We don't need to worry about the file changing under us any more; this
was all pre-zuul, let alone pre-using-swift for logs. Remove this
workaround.
Change-Id: I5938dcef5550d4c62c8158c5f89ace75ae99aedc
We are now logging to swift and store the objects as deflate encoded
data [1]. This means that we get back "Content-Encoding: deflate"
data when downloading the logs (even despite us not accepting that).
So put in a path for deflate encoding to the extant code with zlib.
For completeness we also update our Accept-Encoding: header to show we
accept deflate.
[1] 60e7542875/roles/upload-logs-swift/library/zuul_swift_upload.py (L608)
Change-Id: I328bafea3ddae858fd77af043f16c499ddd5a30e
By default geard only listens on ipv4 0.0.0.0 which means ipv6
connectiosn don't work. Because we run dual stack and things expect ipv6
to work (we have AAAA dns records after all) force geard to listen on ::
which will accept ipv6 and ipv4 connections.
Change-Id: Ibf3bfc5f80ca139b375ee2902dc3149ac791ef96
This adds severity as a logstash field for every oslo formatted
log line, and does not add any lines which are at DEBUG level.
This means we no longer rely on the level=INFO query paremeter
in order to remove DEBUG lines, so we will avoid sending them
to logstash regardless of whether os-loganalyze is used.
Change-Id: I8c4ac76a7fa0c3badd82fc7c54959ef6eb052732
We don't use the jenkins log client 0mq events anymore with zuulv3.
Instead zuul jobs submit the log indexing jobs directly to the gearman
queue for log processing. This means we only need a geard to be running
so add support for running just that daemon.
Change-Id: Iedcb5b29875494b8e18fa125adb08ec2e34d0064
Log files come with many names while still containing the same logical
content. That may be because the path to them differs (eg /var/log/foo.log
and /opt/stack/log/foo.log) or due to file rotations (eg
/var/log/foo.log and /var/log/foo.log.1) or due to compression (eg
/var/log/foo.log and /var/log/foo.log.gz). At the end of the day these
are all the same foo.log log file.
This means when we do machine learning on the log files we can collapse
all these different cases down into a single case that we learn on. This
has become more important with the recent running out of disk space due
to all the non unique log paths out there for our log files but should
also result in better learning.
Change-Id: I4ba276870b73640909ac469b336a436eb127f611
We are having OOM problems with larger log files. Attempt to make this
more robust by having much smaller internal log line message queues (we
reduce the queue size to about 10% the original size). The idea here is
that if we have the old 130k queue size full then grab a large log file
the overhead there is fairly significant whereas if we have a small 16k
queue size and grab a large log file we really only have to worry about
the size of the logfile itself.
Depends-On: Iddbbab9ea5996df4922bf7927deb8f0354378ab7
Change-Id: I761fabaa1b5aae64790def721980151f9fdc720d
We were previously sending events for every file we attempted to
process, not just those that were processed and also for every single
log line event. This effectively doubled the io performed by the
logstash workers which seemed to slow the whole pipeline down. Trim it
down to only recording events for log files that are processed which
should significantly trim down the total number of events.
Change-Id: I0daf3eb2e2b3240e3efa4f2c7bac57de99505df0
Previously the mqtt topic generation always assumed a build_change was
present. However there are some cases where the isn't a build_change in
the metadata, like periodic, post, and release jobs. This commit handles
those edge cases so it uses the build queue in the topic instead of the
build_change. If that doesn't work the topic is just the project.
Change-Id: I26dba76e3475749d00a45b076d981778f885c339
There was bad indentation and a missing '.' in config.get.
_generate_topic())_ is an object method not global function and it takes
an action argument.
Change-Id: I01c4af83cf98f0d7191041a864618a1608f97647
This commit adds support to the gearman worker for publishing an mqtt
message when processing a gearman job succeeds or fails. It also adds
a message for when the processor passes the logs to logstash either via
stdout or over a socket. By default this is disabled since it requires
extra configuration to tell the worker how to talk to the mqtt broker.
Depends-On: Id0308d2d4d1843fcca73f459cffa2ae944bebd0c
Change-Id: I43be3562780c61591ebede61f3a8929e8217f199
We had been running at debug level which is incredibly verbose. Remove
the -d flag. This will cause the logs which are logged to go to
stdout/err which should mean that upstart (or whatever init system) will
deal with them for us.
We should properly clean this up so that debug logging is useful again
in the long term.
Change-Id: I613c135ea56507d083df8c66e8846c6fbfa8b2ed
As part of the move to logstash 2.0 we are relying on upstream packaging
for logstash. This packaging replaces a lot of the micromanagement of
users and groups and dirs that was done in puppet for logstash. This is
great news because its less work for us but means that the log
processors can't rely on puppet resources for those items and we don't
actually want to install logstash package everywhere we run log
processor daemons.
Since the log processors don't need a logstash service running and
actually don't need any of the logstash stuff at all decouple them
completely and have the log processor daemons use their own user, group,
log dir, config dir, etc. With this in place we can easily switch to
using the logstash packages only where we actually need logstash to be
running.
Change-Id: I2354fbe9d3ab25134c52bfe58f562dfdf9ff6786
The python scripts have been moved to their own project at
openstack-infra/log_processor. Delete the files here and start
installing that project from source. As a part of this split, the
.py extension has been dropped from the filename of the installed
executables.
Change-Id: Ied3025df46b5014a092be0c26e43d4f90699a43f
The node region can be figured out from the build_node very easily and
having a discrete field will make filtering to a single region much
simpler. This commit adds a new metadata field 'node_region' which is
the cloud region that the build_node ran in.
Change-Id: I06bbb62d21871ee61dbfb911143efff376992b98
This reverts commit 135ac1809d.
EventProcessor was called before being defined. The code also doesn't
look entirely right. Reverting this to fix up the logstash servers
Change-Id: I2fb8081426646565814090c152d04d7349c16945
Read the ZUUL_VOTING parameter and add to the event before posting for
log processing.
The plan is that elastic-recheck will eventually use this field for
filtering out non-voting jobs from the e-r uncategorized bugs page.
Depends-On: I40746bb77aab900c1dd2637f940c14f72a904a61
Change-Id: I1f3c2a65104db39fdd7d786d421cded1b436a5f6
Currently logstash does not track the zuul url. The zuul url
contains the zm (zuul merger) node identifier.
While trying to troubleshoot a zuul cloning issue, I noticed all
faiures were coming from the same zm (zuul merger) node. Tracking
the build_zuul_url can be helpful. This patch adds the
build_zuul_url parameter.
Change-Id: I83358dc0d9b27852df2395a9c52d2daaaeda712b
Previously this was using socket.getaddrinfo() without importing socket
and causing the daemon to fail. Running in the foreground did not use
statsd thus did not attempt to resolve the statsd host which is how this
got past manual testing. Import socket to get everything working agian.
Change-Id: I280973bdcdf472736a07d19173559b062ed74d3c
Implement a project-filter option to gearman client config alongside the
job-filter and build-queue-filter options.
Change-Id: Ia71f216f4acc9de145eb9124df691393d2a86808
Because boot order is such a mess we will lazily connect to the logstash
TCP/UDP ports to allow for logstash to come up before we start writing
to it. This takes advantage of existing logstash restart handler code in
the log processors.
Change-Id: I836c55806c88cc86b7973b3d40f4bfce076970f5
There is no sane way to convince Ubuntu to start these services after
name resolution is working (because sysv init is horribly broken on
Ubuntu). Work around this by catching EAI_AGAIN errors during name
resolution and retrying until we can resolve names.
This logs each failed resolution attempt so that users are aware of the
issue if investigating logs.
Change-Id: If94d4f04d0e1cfedc358fd9d678a36fc9cd8aa7b
Log processing requires networking and name resolution to be available.
Specify these deps in the LSB init headers so that we get proper boot
time start sequences for these services.
Change-Id: Ic36eba2654e7425f3aba8ee5c215150b7d94d658
This commit adds a new job filter to the gearman client to filter
based on the build queue. This is used for the subunit jobs which
we don't want to run on check jobs.
Change-Id: If81fe98d8d67bb718c53a963695a7d06f5f6625d
This adds a new gearman worker to process the subunit files from
the gate job runs. It will use subunit2sql to connect to a sql
server and process the data from the subunit file. The
log-gearman-client is modified to allow for pushing subunit jobs
to gearman, and the worker model for processsing logs is borrowed
to process the subunit files.
Change-Id: I83103eb6afc22d91f916583c36c0e956c23a64b3
We are leaking file descriptors in our log worker processes because we
are are not catch all possible errors leaving some actions left behind
to do. More aggressively catch errors so that all cleanup happens
Change-Id: I7a73a36c6fc42d4eba636cf36c8cfffcea48a318
According to https://docs.python.org/3/howto/pyporting.html the
syntax changed in Python 3.x. The new syntax is usable with
Python >= 2.6 and should be preferred to be compatible with Python3.
Enabled hacking check H231.
Change-Id: I4c20a04bc7732efc2d4bbcbc3d285107b244e5fa
The openstack logs a full of various IDs and UUIDs but they are not
uniquely special when it comes to filtering them. Instead replace each
ID with a token making CRM114's life much easier.
Change-Id: Id9b430c0d31889b89e4e0c1790a2405d73f501b5
We are currently using a lot of wildcard searches in elasticsearch which
are slow. Provide better field data so that we can replace those
wildcard searches with filters. In particular add a short uuid field and
make the filename tag field the basename of the filepath so that grenade
and non grenade files all end up with the same tags.
Change-Id: If558017fceae96bcf197e611ab5cac1cfe7ae9bf
Have the log-gearman-client (aka jenkins-log-client) initialize
the statsd parameters when starting the geard server. Also, make
sure that the python statsd package is installed on the host.
Change-Id: I04fe1a7609f08bc710891b6a3b92d0f4d156d86c
If there is an exception filtering a log event handle that by removing
the filter and continuing to process the remaining log events for the
assocaited file. This prevents non filter data from being lost when the
filters have an exception.
Change-Id: I65141daf21a873096829c41fdc2c77cbeecde2e3
CRM 114 is being forked off of the gearman worker processes and as a
result has open fds for log files and tcp connections. CRM 114 should be
isolated from the fds so that it doesn't crash when they change
unexpectedly. Close the fds using the subprocess.Popen close_fds flag.
Change-Id: I4fbdf3564771be7d7a7e4c518e571634de576253
Clark Boylan