It’s okay to hate the 12 year old boys who write the bulk of OpenSource code

Even if their biological clock states they are north of 40, they never got past 12 when it comes to coding. In case you can’t see the featured image, the source file came from here. And since they will _hopefully_ sweep that up, here is the first snippet.

/* this creates a timestamp based on current time according to the
 * fine rules of RFC3164, most importantly it ensures in a portable
 * way that the month day is correctly written (with a SP instead
 * of a leading 0). The function uses a static buffer which is
 * overwritten on the next call (just like ctime() does).
 */
static char const *rfc3164_current_time(void)
{
	static char time[32];
	struct timeval tv;
	struct tm *tm;
	static char const * const monthnames[] = {
		"Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug",
		"Sep", "Oct", "Nov", "Dec"
	};

	logger_gettimeofday(&tv, NULL);
	tm = localtime(&tv.tv_sec);
	snprintf(time, sizeof(time),"%s %2d %2.2d:%2.2d:%2.2d",
		monthnames[tm->tm_mon], tm->tm_mday,
		tm->tm_hour, tm->tm_min, tm->tm_sec);
	return time;
}

The second problem is they are returning the address of a variable which is inside of the function. Those bounding {} of the function delineate the scope. The static qualifier means the function is only visible from within this source file. So, to try and defeat this, our little 12 year old stuck a static qualifier on the character array (string). ___Maybe___ in the latest and greatest C standard (which I haven’t read) the compiler is now required to BOTH save the value AND keep it externally accessible while the rest of the routine is being garbage collected away.

You see, the definition which was/is in most of the compilers out there, especially those which stopped updating at C99 or a bit sooner, that’s not a requirement. The “requirement” was that the variable only be initialized once and that it retain its value across multiple function calls. There was/is nothing about it still being externally accessible.

When you are writing OpenSource, you aren’t writing for the latest and greatest, you are writing for whatever happens to be out there.

While we are at it, choose “time” for a variable name, especially for a string, is Uber stupid. I couldn’t believe it compiled. My gut tells me that if this code really is working on PC platforms it is working due to a bad architecture and compiler with shit garbage collection.

Don’t worry, I’m not going to cover it all, this would be  a 2+ million word blog post if I did that.

#define NILVALUE "-"
static void syslog_rfc3164_header(struct logger_ctl *const ctl)
{
	char pid[30], *hostname;

	*pid = '\0';
	if (ctl->pid)
		snprintf(pid, sizeof(pid), "[%d]", ctl->pid);

	if ((hostname = logger_xgethostname())) {
		char *dot = strchr(hostname, '.');
		if (dot)
			*dot = '\0';
	} else
		hostname = xstrdup(NILVALUE);

	xasprintf(&ctl->hdr, "<%d>%.15s %s %.200s%s: ",
		 ctl->pri, rfc3164_current_time(), hostname, ctl->tag, pid);

	free(hostname);
}

You see, I started cross compiling this because adding all of the advertised features to the existing logger for OpenVMS was going to take several days to a week. Cross compiling this _should_ have been quicker. Yes, the current C compiler

$ cc/ver
HP C V7.1-015 on OpenVMS Alpha V8.3

Stopped around the time of the C99 standard. I won’t go so far as to say C99 is “all” there. I’ve banged into some partially implemented stuff with the networks, but haven’t dug in to see if they are part of the standard or not.

So the above snippet nests a call to our original snippet inside of a print routine. Once this got ported to OpenVMS I could step through the first snippet and see a perfectly formatted date string. When the sprintf() got done I had a big block-o-nothin where the date should be.

Old Timers, we know these things. Global data isn’t a bad thing, it exists because we need it. All of these little tricks trying to bob and weave around the Grim Reaper of garbage collection are just time bombs waiting to go off. So, a quick cut and paste moving that static char definition of time to global scope brought about the expected compilation error.

static char time[32]; /* place to store a time return value */
............^
%CC-W-MIXLINKAGE, In this declaration, "time" is declared with both internal and external linkage. The previous declaration is at l
ine number 378 in file SYS$COMMON:[SYSLIB]DECC$RTLDEF.TLB;1 (text module TIME).
at line number 112 in file RADIAN_ROOT:[2018-VMS-SYSLOG]logger.c;148

So, changing time[32] to time_str[32] and changing the few references to it brought about the desired outcome. What “could” have been the problem?

  • Grim Reaper garbage collection is faster on old DS-10 than modern Intel PC
  • DECC puts the value in a safe place when function goes out of scope and reassigns value when function is re-entered. The original storage location, however, is garbage collected.
  • Choosing “time” as a variable name, especially for a string, was an incredibly stupid thing to do and it collided with the OS level definition in a way which whacked the string value once outside of the function.
  • Compiler developers, having been told for years by unemployable academics without a single line of QA’ed code in production at any for-profit company that global data is bad, came up with a tweaking of the “static” definition to avoid making global what obviously needed to be global. This was done without concern for existing compilers or code in production.

You can probably come up with more.

The point is, the 12 year old boys always want to play with the new toys while the production coders will keep it simple. Production coders who go to independent QA departments know better than to push the envelop. Code they write today could be ported to a Z-80 chip with a 1980s compiler. You think I’m kidding? There are production systems today still running OS/2 Warp.

OS/2 Warp job posting

Oh, and for the record. I knew it would take 3 days to a week to add the bulk of the features to the existing ported code. This __should__ have taken one day to port. I’m now on day 3 tracking down stuff like this. Too close to finished to quit.

Thanks!

 

 

Raspberry Qt – Part 6

Logging information in Linux

In the zip file you will notice logikallogger.cpp and its header file. This is a class I have written over and over through the years, even before I got into Qt. Any time you are developing for an OS which has a central log system as Linux does you should have a class like this in your application.

Yes, I know many in the C++ world decry the use of a singleton class, but they, like the much maligned goto statement, have a purpose. Even Java did not get rid of the goto statement, they just gave it different names. Even a switch statement is a variation of BASIC’s “ON GOTO” statement. When you enter a switch you goto the case matching the conditional value and when you encounter the break statement you goto the code immediately following the switch.

I will be the first to admit both the singleton class and the goto statement have been viciously abused in production code around the world. When it comes to a singleton class you know you hosed its creation when you feel a need to derive from it. Tsk, tsk, tsk. When it comes to something like application access to a central error logger a singleton class makes perfect sense. No, I’m not going to paste and dissect the code. That is something I do in my books. I will cut and paste the very short main.cpp module. It looks like most every other Qt application main module with the addition of 2 lines for the logger. You really need to set the application name so you can find your messages in syslog.

/*********************************************************************
 * Copyright (c) 2016, Logikal Solutions  All Rights Reserved.
 *
 * File:             main.cpp
 *
 * Creation date:    2016
 * Author:           Roland Hughes
 *
 * Description: Main module for SerialKeypad example
 *********************************************************************/
#include "mainwindow.h"
#include "logikallogger.h"
#include <QApplication>

int main(int argc, char *argv[])
{
    QApplication a(argc, argv);
    MainWindow w;
    LogikalLogger::Instance().setAppName("SerialKeypad");
    w.show();

    return a.exec();
}

Before the application runs it is best to open a terminal window and type:

sudo tail -f /var/log/syslog

After it completes hit return a couple of times. Most of the messages appearing after the blank space should come from your run. Connecting the cable to the serial port of my Pi with the device powered on yields a screen like the one below.

getty_test_1

Clicking enter after using the mouse to type my name yields this resulting screen.

getty_test_2

If you don’t see the same result you most likely also don’t see your mini-tester looking like this with the application open and connected to the Pi.

0726161420a

Your terminal window should also should also show something which looks much like the following:

Jul 26 14:17:47 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: Result of connecting signal mapper 1
Jul 26 14:17:47 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: Testing: ttyS0 manufacturer:  description:  serial number:  baud: 9600 data: 8 parity: 0 stop: 1
Jul 26 14:17:47 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: port ttyS0 chosen as device
Jul 26 14:17:47 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: Testing: ttyS4 manufacturer:  description:  serial number:  baud: 9600 data: 8 parity: 0 stop: 1
Jul 26 14:17:47 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: Attempting to open ttyS0
Jul 26 14:17:47 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: Serial Device ttyS0 opened on first attempt
Jul 26 14:18:02 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: Sending message: ROLAND
Jul 26 14:18:02 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: SerialThread writing message: ROLAND
Jul 26 14:18:02 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: SerialThread received data: ROLAND
Jul 26 14:18:02 roland-HP-Compaq-8100-Elite-SFF-PC LogikalLogger: Received message: ROLAND

Why is it better to use the OS logger than your own log file? Because if something else happened on the system causing your program to misbehave it “should” show up in the system log. Entries are in timestamp sequence. If some device driver or piece of hardware throws an error the driver “should” report it here. I say should because all bets are off if the system disk is throwing errors on its way to that big recycling pile in the sky.

Why does this test work? We haven’t done anything to the Pi other than boot it with Raspbian and connect our serial cable. It shouldn’t work.

Well, it does and this is why I told you not to bludgeon forward. The Pi has a process running called mgetty which expects an ASCII terminal supporting a stripped down VT100 interface. Not a real VT100 interface as defined by OpenVMS but what Linux users call VT100. As such, it echos back characters sent to it until it recognizes something such as a login attempt.