• user warning: Unknown column 'u.signature_format' in 'field list' query: SELECT c.cid as cid,, c.nid, c.subject, c.comment, c.format, c.timestamp,, c.mail, c.homepage, u.uid, AS registered_name, u.signature, u.signature_format, u.picture,, c.thread, c.status FROM comments c INNER JOIN users u ON c.uid = u.uid WHERE c.nid = 22947 AND c.status = 0 ORDER BY c.cid LIMIT 0, 50 in /var/www/ on line 991.
  • warning: file_get_contents( [function.file-get-contents]: failed to open stream: HTTP request failed! in /var/www/ : eval()'d code on line 4.

Troubleshooting Using Log Files

by Thomas Maul

In this blog post, Thomas Maul gives a preview of a topic that he'll explain in great detail as one of the in-depth subjects of the 4D Summit 2011 Pre-class. The Pre-class will give attendees a unique opportunity to learn master-level skills from 4D's senior engineers.


A customer's complaint that "sometimes the server is very slow" or "sometimes the server does not work as expected" is the issue that's most difficult to handle, especially in large environments where you don't have a chance to ask the customer, "What did you do differently?"

By using logs and knowing how to read and analyze them, we can find and understand many of these issues. Even better, using the tools to watch the server behavior in normal times allows us to quickly identify possible issues and resolve them, avoiding potential issues, even before customers notice them.


Starting with 4D v11 SQL, 4D Server provides many log files, allowing detailed off-site analysis helping to understand server behavior and problems. This part of the class will focus on four tools made for this purpose.


4D Cache Log Analyzer

A main highlight of the session is a tool to record the result of the GET CACHE STATISTIC command and to analyze it, giving a clear view about cache memory behavior, such as:


Cache log


It also provides information about cache usage, such as free large blocks, physical or virtual memory, helping to understand an application's memory requirements.



All this data allows us not only to troubleshoot, but also to analyze and understand the an application's memory needs, letting us fine tune memory requirements and settings and create a requirement table, such as for 5, 10, 25, 50, 100 user installations for a specific application and usage.


4D Info Report Component 3.0

The Information Report Component provides important information about the environment, with detailed information about the hardware being used (computer type, CPU, memory, etc), operating system (such as Windows Server R2 SP1) and version of 4D (such as 12.2 Hotfix 2), as well as a snapshot of the current status of used memory, number of users and processes, such as:


Manufacturer:                  	PowerEdge R710
Computer Kind:                 	x64-based PC
Total RAM:                     	16384 MB
Number of Processors:          	2
Processor Name:                	Intel Xeon  E5520
CPU Speed:                     	2.27 GHz
Total number of Cores:         	8
Total number of CPU threads:   	16
Operating System:              	Windows Server 2008 Standard SP1 
Application type:              	4D Server (64-bit)
Application version:           	v12 release 2  (F0021220)

This component should be part of any deployed server application, as a first step to understand the situation (also historically) at a customer site. For example, the following chart shows the behavior of the cache used in relation to the number of users and the total count of user processes over a week of usage:


Cache analysis


4D Pop Data Analyzer

4D Pop Data Analyzer is a component that analyzes the size and content of 4D data files. This tool helps to understand the minimum and maximum size requirements of a record and analyses the size requirement depending on the real data, as well as table fragmentation.


4D Pop Data Analyzer


Network Log Analyzer

4D Server’s network log quickly produces a huge amount of data, making it difficult to identify an issue simply because of the mass of packets. The Network Log Analyzer focuses on exceptions, such as very slow or very large packets.


The Network Log Analyzer groups all packets in 5-minute intervals, allowing us to quickly identify any problematic times over the course of a day:


Network log analyzer


This example shows an extremely overloaded server, with average response times between 0.5 and 5 seconds, with a maximum response time up to 113 seconds for a single request.


A double-click quickly leads to the operations involved:


Network log analyzer detail


The packets are sorted by time needed, so it is easy to see that the slowest operation with 113 seconds was a query, followed by another slow query, then a Selection to array taking 25 seconds, then quickly decreasing. The User name/Process name (this is blurred here as it is real customer data) allows us to identify the operation, and another double-click reduces the operations to this single process. Knowing exactly what was done before and after, it is often easy to find the corresponding part of the source code.


Additionally it allows us to synchronize a client debug log with the network log, showing them side by side:


Client debug log



Master this technique and more at the 4D Summit 2011 Pre-class in Boston, Massachusetts, in the company of top 4D engineers and developers from around the world.

RSS 0 comment(s) to this post