The mystery about test1 and test2 kernel warning messages

I've been getting monitoring alerts of suspicious kernel warning messages. I was confused and started auditing the affected box once I saw this:

Apr 22 22:42:51 hv1 kernel: test1
Apr 22 22:42:51 hv1 kernel: test2

It was an uncomfortable feeling when I realized that during this time there was no visible shell access or any other remote activity going on. While I was already scanning for rootkits I noticed a minor issue with php configuration so I had this idea to search the webserver logfiles for any suspicious activity. And then I found it.

As it turns out a virtual machine had been stopped and started using phpVirtualBox. I've diffed the code and saw no differences in any of the PHP files. So I would stop and start the affected VM to see what happens. And indeed, the messages would occur once again.

After a while I nailed it down to VirtualBox 6.0.6 so I grabbed the source code and started investigating. And look what I found:

src/VBox/HostDrivers/Support/linux/SUPDrv-linux.c:    printk("test2\n");
src/VBox/HostDrivers/Support/linux/SUPDrv-linux.c:    printk("test1\n");

The best way to freak out secops on a lonely sunday night, why not send some “test1” kernel warning messages. Looks like a developer left some “debug code” in there. I've reported this issue on #vbox-dev on Freenode and it was removed by the next morning. Kudos for the fast reaction.

If you are being pestered by this and you are running the (at the time of this writing) current version of VirtualBox, please do not hesitate to filter these warning messages from your syslog daemon. In the case of rsyslog, you would add two simple lines to /etc/rsyslog.conf:

:msg, contains, "test1" stop
:msg, contains, "test2" stop