Go forward in time to July 2022.
In this line of work, we all stumble at least once upon a problem that turns out to be extremely elusive and very tricky to narrow down and solve. If we're lucky, we might have everything at our disposal to diagnose the problem but sometimes that's not the case – and in embedded development it's often not the case. Add to the mix proprietary drivers, lack of debugging symbols, a bug that's very hard to reproduce under a controlled environment, and weeks in partial confinement due to a pandemic and what you have is better described as a very long lucid nightmare. Thankfully, even the worst of nightmares end when morning comes, even if sometimes morning might be several days away. And when the fix to the problem is in an inimaginable place, the story is definitely one worth telling.
It all started with one of Igalia's customers deploying a WPE WebKit-based browser in their embedded devices. Their CI infrastructure had detected a problem caused when the browser was tasked with creating a new webview (in layman terms, you can imagine that to be the same as opening a new tab in your browser). Occasionally, this view would never load, causing ongoing tests to fail. For some reason, the test failure had a reproducibility of ~75% in the CI environment, but during manual testing it would occur with less than a 1% of probability. For reasons that are beyond the scope of this post, the CI infrastructure was not reachable in a way that would allow to have access to running processes in order to diagnose the problem more easily. So with only logs at hand and less than a 1/100 chances of reproducing the bug myself, I set to debug this problem locally.
The first that became evident was that, whenever this bug would occur, the WebKit feature known as web extension (an application-specific loadable module that is used to allow the program to have access to the internals of a web page, as well to enable customizable communication with the process where the page contents are loaded – the web process) wouldn't work. The browser would be forever waiting that the web extension loads, and since that wouldn't happen, the expected page wouldn't load. The first place to look into then is the web process and to try to understand what is preventing the web extension from loading. Enter here, our good friend GDB, with less than spectacular results thanks to stripped libraries.
#0 0x7500ab9c in poll () from target:/lib/libc.so.6
#1 0x73c08c0c in ?? () from target:/usr/lib/libEGL.so.1
#2 0x73c08d2c in ?? () from target:/usr/lib/libEGL.so.1
#3 0x73c08e0c in ?? () from target:/usr/lib/libEGL.so.1
#4 0x73bold6a8 in ?? () from target:/usr/lib/libEGL.so.1
#5 0x75f84208 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#6 0x75fa0b7e in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#7 0x7561eda2 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#8 0x755a176a in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#9 0x753cd842 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#10 0x75451660 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#11 0x75452882 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#12 0x75452fa8 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#13 0x76b1de62 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#14 0x76b5a970 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#15 0x74bee44c in g_main_context_dispatch () from target:/usr/lib/libglib-2.0.so.0
#16 0x74bee808 in ?? () from target:/usr/lib/libglib-2.0.so.0
#17 0x74beeba8 in g_main_loop_run () from target:/usr/lib/libglib-2.0.so.0
#18 0x76b5b11c in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#19 0x75622338 in ?? () from target:/usr/lib/libWPEWebKit-1.0.so.2
#20 0x74f59b58 in __libc_start_main () from target:/lib/libc.so.6
#21 0x0045d8d0 in _start ()
From all threads in the web process, after much tinkering around it
slowly became clear that one of the places to look into is
that poll()
call. I will spare you the details related to what other threads were
doing, suffice to say that whenever the browser would hit the bug,
there was a similar stacktrace in one thread, going
through libEGL to a
call to poll()
on top of the stack, that would never
return. Unfortunately, a stripped EGL driver coming from a proprietary
graphics vendor was a bit of a showstopper, as it was the inability to
have proper debugging symbols running inside the device (did you know
that a non-stripped WebKit library binary with debugging symbols can
easily get GDB and your device out of memory?). The best one could do
to improve that was to use the
gcore
feature in GDB, and extract a core from the device for post-mortem
analysis. But for some reason, such a stacktrace wouldn't give
anything interesting below the poll()
call to understand
what's being polled here. Did I say this was tricky?
Because WebKit is a multiprocess web engine, having system calls
that signal, read, and write in sockets communicating with other
processes is an everyday thing. Not knowing what a poll()
call is doing and who is it that it's trying to listen to, not
very good. Because the call is happening under the EGL library, one
can presume that it's graphics related, but there are still
different possibilities, so trying to find out what is this polling is
a good idea.
A trick I learned while debugging this is that, in absence of
debugging symbols that would give a straightforward look into
variables and parameters, one can examine the CPU registers and try to
figure out from them what the parameters to function calls are. Let's
do that with poll()
. First, its signature.
int poll(struct pollfd *fds, nfds_t nfds, int timeout);
Now, let's examine the registers.
(gdb) f 0
#0 0x7500ab9c in poll () from target:/lib/libc.so.6
(gdb) info registers
r0 0x7ea55e58 2124766808
r1 0x1 1
r2 0x64 100
r3 0x0 0
r4 0x0 0
Registers r0
, r1
, and r2
contain poll()
's three
parameters. Because r1
is 1, we know that there is only
one file descriptor being polled. fds
is a pointer to an
array with one element then. Where is that first element? Well, right
there, in the memory pointed to directly by
r0
. What does struct pollfd
look like?
struct pollfd {
int fd; /* file descriptor */
short events; /* requested events */
short revents; /* returned events */
};
What we are interested in here is the contents of fd
,
the file descriptor that is being polled. Memory alignment is again in
our side, we don't need any pointer arithmetic here. We can
inspect directly the register r0
and find out what the
value of fd
is.
(gdb) print *0x7ea55e58
$3 = 8
So we now know that the EGL library is polling the file descriptor
with an identifier of 8. But where is this file descriptor coming
from? What is on the other end? The /proc
file system can
be helpful here.
# pidof WPEWebProcess
1944 1196
# ls -lh /proc/1944/fd/8
lrwx------ 1 x x 64 Oct 22 13:59 /proc/1944/fd/8 -> socket:[32166]
So we have a socket. What else can we find out about it? Turns out,
not much without
the unix_diag
kernel module, which was not available in our device. But we are
slowly getting closer. Time to call another good friend.
printf()
triumphsSomething I have learned from many years working with a project as
large as WebKit, is that debugging symbols can be very difficult to
work with. To begin with, it takes ages to build WebKit with them.
When cross-compiling, it's even worse. And then, very often the
target device doesn't even have enough memory to load the symbols
when debugging. So they can be pretty useless. It's then when
just
using fprintf()
and logging useful information can simplify things. Since we know that
it's at some point during initialization of the web process that
we end up stuck, and we also know that we're polling a file
descriptor, let's find some early calls in the code of the web
process and add some
fprintf()
calls with a bit of information, specially in
those that might have something to do with EGL. What can we find out
now?
Oct 19 10:13:27.700335 WPEWebProcess[92]: Starting
Oct 19 10:13:27.720575 WPEWebProcess[92]: Initializing WebProcess platform.
Oct 19 10:13:27.727850 WPEWebProcess[92]: wpe_loader_init() done.
Oct 19 10:13:27.729054 WPEWebProcess[92]: Initializing PlatformDisplayLibWPE (hostFD: 8).
Oct 19 10:13:27.730166 WPEWebProcess[92]: egl backend created.
Oct 19 10:13:27.741556 WPEWebProcess[92]: got native display.
Oct 19 10:13:27.742565 WPEWebProcess[92]: initializeEGLDisplay() starting.
Two interesting findings from the fprintf()
-powered
logging here: first, it seems that file descriptor 8 is one known to
libwpe
(the general-purpose library that powers the WPE WebKit port). Second,
that the last EGL API call right before the web process hangs
on poll()
is a call
to eglInitialize()
. fprintf()
,
thanks for your service.
We now know that the file descriptor 8 is coming from WPE and is not internal to the EGL library. libwpe gets this file descriptor from the UI process, as one of the many creation parameters that are passed via IPC to the nascent process in order to initialize it. Turns out that this file descriptor in particular, the so-called host client file descriptor, is the one that the freedesktop backend of libWPE, from here onwards WPEBackend-fdo, creates when a new client is set to connect to its Wayland display. In a nutshell, in presence of a new client, a Wayland display is supposed to create a pair of connected sockets, create a new client on the Display-side, give it one of the file descriptors, and pass the other one to the client process. Because this will be useful later on, let's see how is that currently implemented in WPEBackend-fdo.
int pair[2];
if (socketpair(AF_UNIX, SOCK_STREAM | SOCK_CLOEXEC, 0, pair) < 0)
return -1;
int clientFd = dup(pair[1]);
close(pair[1]);
wl_client_create(m_display, pair[0]);
The file descriptor we are tracking down is the client file
descriptor, clientFd
. So we now know what's going on in this socket:
Wayland-specific communication. Let's enable Wayland debugging next,
by running all relevant process with WAYLAND_DEBUG=1
. We'll get back
to that code fragment later on.
Turns out that enabling Wayland debugging output for a few processes is enough to alter the state of the system in such a way that the bug does not happen at all when doing manual testing. Thankfully the CI's reproducibility is much higher, so after waiting overnight for the CI to continuously run until it hit the bug, we have logs. What do the logs say?
WPEWebProcess[41]: initializeEGLDisplay() starting.
-> wl_display@1.get_registry(new id wl_registry@2)
-> wl_display@1.sync(new id wl_callback@3)
So the EGL library is trying to fetch the Wayland
registry and it's doing a wl_display_sync()
call
afterwards, which will block until the server responds. That's
where the blocking poll()
call comes from. So, it turns
out, the problem is not necessarily on this end of the Wayland socket,
but perhaps on the other side, that is, in the so-called UI process
(the main browser process). Why is the Wayland display not
replying?
Something that is worth mentioning before we move on is how the WPEBackend-fdo Wayland display integrates with the system. This display is a nested display, with each web view a client, while it is itself a client of the system's Wayland display. This can be a bit confusing if you're not very familiar with how Wayland works, but fortunately there is good documentation about Wayland elsewhere.
The way that the Wayland display in the UI process of a WPEWebKit
browser is integrated with the rest of the program, when it uses
WPEBackend-fdo, is through the
GLib
main event loop. Wayland itself has an event loop implementation
for servers, but for a GLib-powered application it can be useful to
use GLib's and integrate Wayland's event processing with the different
stages of the GLib main loop. That is precisely how WPEBackend-fdo is
handling its clients' events. As discussed earlier, when a new client
is created a pair of connected sockets are created and one end is
given to Wayland to control communication with the
client. GSourceFunc
functions are used to integrate Wayland with the application main
loop. In these functions, we make sure that whenever there are pending
messages to be sent to clients, those are sent, and whenever any of
the client sockets has pending data to be read, Wayland reads from
them, and to dispatch the events that might be necessary in response
to the incoming data. And here is where things start getting really
strange, because after doing a bit of
fprintf()
-powered debugging inside the Wayland-GSourceFuncs functions,
it became clear that the Wayland events from the clients were never
dispatched, because the dispatch()
GSourceFunc
was not being called,
as if there was nothing coming from any Wayland client. But how is
that possible, if we already know that the web process client is
actually trying to get the Wayland registry?
To move forward, one needs to understand how the GLib main loop
works, in particular, with Unix file descriptor sources. A very brief
summary of this is that, during an iteration of the main loop, GLib
will poll file descriptors to see if there are any interesting events
to be reported back to their respective sources, in which case the
sources will decide whether to trigger the dispatch()
phase. A simple source might decide in its dispatch()
method to directly read or write from/to the file descriptor; a
Wayland display source (as in our case), will
call wl_event_loop_dispatch()
to do this for us.
However, if the source doesn't find any interesting events, or if
the source decides that it doesn't want to handle them,
the dispatch()
invocation will not happen. More on the
GLib main event loop in
its API
documentation.
So it seems that for some reason the dispatch()
method is not being
called. Does that mean that there are no interesting events to read
from? Let's find out.
Here we resort to another helpful
tool, strace
. With strace
we can try to figure out what is happening when the main loop polls
file descriptors. The strace
output is huge (because it
takes easily over a hundred attempts to reproduce this), but we know
already some of the calls that involve file descriptors from the code
we looked at above, when the client is created. So we can use those
calls as a starting point in when searching through the several MBs of
logs. Fast-forward to the relevant logs.
socketpair(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC, 0, [128, 130]) = 0
dup(130) = 131
close(130) = 0
fcntl64(128, F_DUPFD_CLOEXEC, 0) = 130
epoll_ctl(34, EPOLL_CTL_ADD, 130, {EPOLLIN, {u32=1639599928, u64=1639599928}}) = 0
What we see there is, first, WPEBackend-fdo creating a new socket
pair (128, 130) and then, when file descriptor 130 is passed to
wl_client_create()
to
create a new client, Wayland adds that file descriptor to its
epoll()
instance
for monitoring clients, which is referred to by file descriptor 34. This way, whenever there are
events in file descriptor 130, we will hear about them in file descriptor 34.
So what we would expect to see next is that, after the web process
is spawned, when a Wayland client is created using the passed file
descriptor and the EGL driver requests the Wayland registry from the
display, there should be a POLLIN
event coming in file
descriptor 34 and, if the dispatch()
call for the source
was called,
a epoll_wait()
call on it, as that is
what wl_event_loop_dispatch()
would do when called from the source's dispatch()
method. But what do we have instead?
poll([{fd=30, events=POLLIN}, {fd=34, events=POLLIN}, {fd=59, events=POLLIN}, {fd=110, events=POLLIN}, {fd=114, events=POLLIN}, {fd=132, events=POLLIN}], 6, 0) = 1 ([{fd=34, revents=POLLIN}])
recvmsg(30, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
strace
can be a bit cryptic, so let's explain
those two function calls. The first one is a poll in a series of file
descriptors (including 30 and 34) for POLLIN
events. The
return value of that call tells us that there is a POLLIN
event in file descriptor 34 (the Wayland display epoll()
instance for clients). But unintuitively, the call right after is
trying to read a message from socket 30 instead, which we know
doesn't have any pending data at the moment, and consequently
returns an error value with an errno
of EAGAIN
(Resource temporarily unavailable).
Why is the GLib main loop triggering a read from 30 instead of 34? And who is 30?
We can answer the latter question first. Breaking on a running UI process instance at the right time shows who is reading from the file descriptor 30:
#1 0x70ae1394 in wl_os_recvmsg_cloexec (sockfd=30, msg=msg@entry=0x700fea54, flags=flags@entry=64)
#2 0x70adf644 in wl_connection_read (connection=0x6f70b7e8)
#3 0x70ade70c in read_events (display=0x6f709c90)
#4 wl_display_read_events (display=0x6f709c90)
#5 0x70277d98 in pwl_source_check (source=0x6f71cb80)
#6 0x743f2140 in g_main_context_check (context=context@entry=0x2111978, max_priority=, fds=fds@entry=0x6165f718, n_fds=n_fds@entry=4)
#7 0x743f277c in g_main_context_iterate (context=0x2111978, block=block@entry=1, dispatch=dispatch@entry=1, self=)
#8 0x743f2ba8 in g_main_loop_run (loop=0x20ece40)
#9 0x00537b38 in ?? ()
So it's also Wayland, but on a different level. This
is the Wayland client source (remember that the browser is also a
Wayland client?), which is installed
by cog (a thin browser
layer on top of WPE WebKit that makes writing browsers easier to do)
to process, among others, input events coming from the parent Wayland
display. Looking
at the cog code, we can see that the
wl_display_read_events()
call happens only if GLib reports that there is
a G_IO_IN
(POLLIN
) event in its file descriptor, but we already
know that this is not the case, as per the strace
output. So at this point we know that there are two things here that
are not right:
Someone here is not telling the truth, and as a result the main loop is dispatching the wrong sources.
It is at this point that it would be a good idea to look at what exactly the GLib main loop is doing internally in each of its stages and how it tracks the sources and file descriptors that are polled and that need to be processed. Fortunately, debugging symbols for GLib are very small, so debugging this step by step inside the device is rather easy.
Let's look at how the main loop decides which sources
to dispatch, since for some reason it's dispatching the wrong ones.
Dispatching happens in
the g_main_dispatch()
method. This method goes over a list of pending source dispatches and
after a few checks and setting the stage, the dispatch method for the
source gets called. How is a source set as having a pending dispatch?
This happens in
g_main_context_check()
,
where the main loop checks the results of the polling done in this
iteration and runs the check()
method for sources that
are not ready yet so that they can decide whether they are ready to be
dispatched or not. Breaking into the Wayland display source, I know
that
the check()
method is called. How does this method decide to be dispatched or
not?
[](GSource* base) -> gboolean
{
auto& source = *reinterpret_cast
In this lambda function we're returning TRUE
or
FALSE
, depending on whether the revents
field in
the GPollFD
structure have been filled during the polling stage of this iteration
of the loop. A return value of TRUE
indicates the main
loop that we want our source to be dispatched. From
the strace
output, we know that there is a
POLLIN
(or G_IO_IN
) condition, but we also know that the main loop is
not dispatching it. So let's look at what's in this GPollFD
structure.
For this, let's go back to g_main_context_check()
and inspect the array
of GPollFD
structures that it received when called. What do we find?
(gdb) print *fds
$35 = {fd = 30, events = 1, revents = 0}
(gdb) print *(fds+1)
$36 = {fd = 34, events = 1, revents = 1}
That's the result of the poll()
call! So far so good. Now the method
is supposed to update the polling records it keeps and it uses when
calling each of the sources check()
functions. What do these records
hold?
(gdb) print *pollrec->fd
$45 = {fd = 19, events = 1, revents = 0}
(gdb) print *(pollrec->next->fd)
$47 = {fd = 30, events = 25, revents = 1}
(gdb) print *(pollrec->next->next->fd)
$49 = {fd = 34, events = 25, revents = 0}
We're not interested in the first record quite yet, but clearly
there's something odd here. The polling records are showing a
different value in the revent
fields for both 30 and 34. Are these
records updated correctly? Let's look at the algorithm that is doing
this update, because it will be relevant later on.
pollrec = context->poll_records;
i = 0;
while (pollrec && i < n_fds)
{
while (pollrec && pollrec->fd->fd == fds[i].fd)
{
if (pollrec->priority <= max_priority)
{
pollrec->fd->revents =
fds[i].revents & (pollrec->fd->events | G_IO_ERR | G_IO_HUP | G_IO_NVAL);
}
pollrec = pollrec->next;
}
i++;
}
In simple words, what this algorithm is doing is to traverse
simultaneously the polling records and the GPollFD
array,
updating the polling records revents
with the results of
polling. From
reading how
the pollrec
linked list is built internally, it's
possible to see that it's purposely sorted by increasing file
descriptor identifier value. So the first item in the list will have
the record for the lowest file descriptor identifier, and so on. The
GPollFD
array is also built in this way, allowing for a
nice optimization: if more than one polling record – that is, more
than one polling source – needs to poll the same file descriptor,
this can be done at once. This is why this otherwise O(n^2) nested
loop can actually be reduced to linear time.
One thing stands out here though: the linked list is only advanced
when we find a match. Does this mean that we always have a match
between polling records and the file descriptors that have just been
polled? To answer that question we need to check how is the array of
GPollFD
structures
filled. This
is done in g_main_context_query()
, as we hinted
before. I'll spare you the details, and just focus on what seems
relevant here: when is a poll record not used to fill
a GPollFD
?
n_poll = 0;
lastpollrec = NULL;
for (pollrec = context->poll_records; pollrec; pollrec = pollrec->next)
{
if (pollrec->priority > max_priority)
continue;
...
Interesting! If a polling record belongs to a source whose priority is lower than the maximum priority that the current iteration is going to process, the polling record is skipped. Why is this?
In simple terms, this happens because each iteration of the main
loop finds out the highest priority between the sources that are ready
in the prepare()
stage, before polling, and then only
those file descriptor sources with at least such a a priority are
polled. The idea behind this is to make sure that high-priority
sources are processed first, and that no file descriptor sources with
lower priority are polled in vain, as they shouldn't be
dispatched in the current iteration.
GDB tells me that the maximum priority in this iteration is -60. From an earlier GDB output, we also know that there's a source for a file descriptor 19 with a priority 0.
(gdb) print *pollrec
$44 = {fd = 0x7369c8, prev = 0x0, next = 0x6f701560, priority = 0}
(gdb) print *pollrec->fd
$45 = {fd = 19, events = 1, revents = 0}
Since 19 is lower than 30 and 34, we know that this record is before theirs in the linked list (and so it happens, it's the first one in the list too). But we know that, because its priority is 0, it is too low to be added to the file descriptor array to be polled. Let's look at the loop again.
pollrec = context->poll_records;
i = 0;
while (pollrec && i < n_fds)
{
while (pollrec && pollrec->fd->fd == fds[i].fd)
{
if (pollrec->priority <= max_priority)
{
pollrec->fd->revents =
fds[i].revents & (pollrec->fd->events | G_IO_ERR | G_IO_HUP | G_IO_NVAL);
}
pollrec = pollrec->next;
}
i++;
}
The first polling record was skipped during the update of
the GPollFD
array, so the condition pollrec
&& pollrec->fd->fd == fds[i].fd
is never going to
be satisfied, because 19 is not in the array. The
innermost while()
is not entered, and as such
the pollrec
list pointer never moves forward to the next
record. So no polling record is updated here, even if we have
updated revent
information from the polling results.
What happens next should be easy to see. The check()
method for all polled sources are called with
outdated revents
. In the case of the source
for file descriptor 30, we wrongly tell it there's a
G_IO_IN
condition, so it asks the main loop to call
dispatch it triggering a a wl_connection_read()
call in a
socket with no incoming data. For the source with file descriptor 34,
we tell it that there's no incoming data and
its dispatch()
method is not invoked, even when on the
other side of the socket we have a client waiting for data to come and
blocking in the meantime. This explains what we see in
the strace
output above. If the source with file
descriptor 19 continues to be ready and with its priority unchanged,
then this situation repeats in every further iteration of the main
loop, leading to a hang in the web process that is forever waiting
that the UI process reads its socket pipe.
I have been using GLib for a very long time, and I have only fixed a couple of minor bugs in it over the years. Very few actually, which is why it was very difficult for me to come to accept that I had found a bug in one of the most reliable and complex parts of the library. Impostor syndrome is a thing and it really gets in the way.
But in a nutshell, the bug in the GLib main loop is that the very
clever linear update of registers is missing something very important:
it should skip to the first polling record matching before attempting
to update its revents
. Without this, in the presence of a
file descriptor source with the lowest file descriptor identifier and
also a lower priority than the cutting priority in the current main
loop iteration, revents
in the polling registers are not
updated and therefore the wrong sources can be dispatched. The
simplest patch to avoid this, would look as follows.
i = 0;
while (pollrec && i < n_fds)
{
+ while (pollrec && pollrec->fd->fd != fds[i].fd)
+ pollrec = pollrec->next;
+
while (pollrec && pollrec->fd->fd == fds[i].fd)
{
if (pollrec->priority <= max_priority)
Once we find the first matching record, let's update all consecutive records that also match and need an update, then let's skip to the next record, rinse and repeat. With this two-line patch, the web process was finally unlocked, the EGL display initialized properly, the web extension and the web page were loaded, CI tests starting passing again, and this exhausted developer could finally put his mind to rest.
A complete patch, including improvements to the code comments around this fascinating part of GLib and also a minimal test case reproducing the bug have already been reviewed by the GLib maintainers and merged to both stable and development branches. I expect that at least some GLib sources will start being called in a different (but correct) order from now on, so keep an eye on your GLib sources. :-)
At this point I should acknowledge that without the support from my colleagues in the WebKit team in Igalia, getting to the bottom of this problem would have probably been much harder and perhaps my sanity would have been at stake. I want to thank Adrián and Žan for their input on Wayland, debugging techniques, and for allowing me to bounce back and forth ideas and findings as I went deeper into this rabbit hole, helping me to step out of dead-ends, reminding me to use tools out of my everyday box, and ultimately, to be brave enough to doubt GLib's correctness, something that much more often than not I take for granted.
Thanks also to Philip and Sebastian for their feedback and prompt code review!
Go backwards in time to December 2016.