I'm noticing unusual issues with the database log. Does the following bother anyone else?
[2016/05/02@07:13:22.212-0600] P-25827 T-1 I ABL 327: (915) Lock table overflow, increase -L on server [2016/05/02@07:13:22.386-0600] P-24191 T-1 I ABL 273: (915) Lock table overflow, increase -L on server [2016/05/02@13:13:22.000+0000] P-21879 T-1 I ABL 44: (562) HANGUP signal received. [2016/05/02@13:13:22.000+0000] P-21879 T-1 I ABL 44: (562) HANGUP signal received. [2016/05/02@07:13:22.443-0600] P-21879 T-1 I ABL 44: (453) Logout by on /dev/pts/t7g. [2016/05/02@07:13:22.618-0600] P-24191 T-1 I ABL 273: (915) Lock table overflow, increase -L on server
I can't think why the OE RDBMS would think its a good idea to alternate between different timezones from one line of the log file to the next. Perhaps the piece of software that writes the "(562) HANGUP signal received." is written from a separate and oblivious thread that is unable to respect the log's timezone preference? Note that the vast majority of the log file is written with the non-utc timezone ( "-600" ) .
This inconsistency can cause a lot of problems. When you are searching for something in the logs (with vi, grep, or whatever) and come across a line written with the UTC timezone, instead of the standard one, it is unexpected and it causes the log to be misinterpreted, unless you are looking out for the timezone offset and comparing the full "DATETIME-WITH-TZ" to the neighbors before and after.
Moreover another thing that is different about those lines (HANGUP signal received) is that they seen to truncate the milliseconds so that these lines appear to show up out of the correct sequence. It can cause problems if the logs were to be parsed and analyzed with a utility.
The OE RDBMS is not alternating TZs. The ABL user is in a different TZ. Each shared memory process writes its own messages to the log file.
Nice catch on the HANGUP msg. I never noticed that.
The signal handler cannot use the same C runtime-library conversion functions as everything else because they are not async signal safe.
IMO all database log messages should be in UTC. Period. No excpetions.
Article: Database stalls on Linux because self-service OpenEdge client deadlocks if it receives hangup signal at the wrong time
<quote>
Upgrade to OpenEdge 11.4 or later
A partial fix is included in OpenEdge 11.2.1 and 11.3.x
As a side effect of the fix, messages from signal handlers will always show as UTC time instead of the database's timezone.
</quote>
Nice catch George. Don't know how you found that, but its probably the key.
Personally I don't think every database client should be using separate logic to write to the logs, or changing the format of timestamps using alternating timezones, or arbitrarily truncating milliseconds. For one thing, the *clients* don't go back and read the logs. The logs should have a target audience in mind ( server managers / dba's / whatever ) and write the log entries accordingly. Gus mentioned writing database log messages in UTC. Is there a mechanism for that? Or do we have to change the timezone environment used by the server itself.