Chapter 13. Troubleshooting

Most DFdiscover messages are written to the syslog "user" facility, with a severity level of "err" or "crit" for more serious errors. DFdiscover daemon messages are written to the syslog "daemon" facility. The default severity level is "notice". DFedcservice also issues login and study access messages at the "warning" level and extensive logging messages at the "info" level that are ignored by syslog using the default configuration.

The logged message includes a syslog message header and a message body. The message header consists of a facility indicator, a severity level indicator, a timestamp, a tag string, and optionally the process ID. The message body contains information specific to DFdiscover. This includes the hostname of the machine that it occurred on, and the application name that generated the error message.

The format of this header information is as follows:

SYSLOG_HEADER machine program[username:studynumber:PID]: message
(1)           (2)     (3)     (4)      (5)         (6)   (7)

When unexpected events or errors occur in a DFdiscover system, the first place to start looking is in the system error log.

It is essential to the correct operation of DFdiscover that only one copy of the process be running at any one time. When a DFmaster.rpcd process is already running, the DFdiscover system and the UNIX system (through the portmapper) are able to enforce this requirement. However, when DFmaster.rpcd is starting and before it has a chance to register itself with the portmapper, it may occur that two independent processes or users attempt to start more than one . To prevent this from occurring, the DFmaster.rpcd process tests for and then creates the lock directory, /opt/dfdiscover/work/DFmaster.rpcd.lock, at the beginning of its initialization. If the lock directory already exists, the following message appears:

DFmaster.rpcd[25859]: another process is starting a master daemon or the
daemon has been disabled - waiting 20 seconds before retry...
DFmaster.rpcd[25859]: another process is starting a master daemon or the daemon
has been disabled - waiting 40 seconds before retry...
DFmaster.rpcd[25859]: another process is starting a master daemon or the daemon
has been disabled - waiting 60 seconds before retry...
DFmaster.rpcd[25859]: another process is starting a master daemon or the daemon
has been disabled - waiting 80 seconds before retry...
DFmaster.rpcd: failed to start service

and the process exits without starting (as another DFmaster.rpcd is presumably starting at the same time). If the lock directory does not exist, it is created and subsequently removed by DFmaster.rpcd after it has successfully registered the UNIX portmapper.

When a slave process starts, it follows the same sequence of initialization steps that the master does, and it too needs to ensure that only one slave process is executing. In the case of the slave process it is however true that there can be multiple slaves across a DFdiscover network, but never more than one on any given computer. Hence, a starting slave creates a lock directory in a directory that is local to the machine rather than in shared directory space. In particular, the lock is created as /tmp/DFslave.rpcd.hostname.lock.

On (mis-configured) systems where /tmp is not writable by everyone, a DFdiscover slave cannot be started (there will likely be other non-DFdiscover problems as well). This is an administrative issue to keep in mind if the /tmp directory is modified.

The DFdiscover processes log all unexpected events to the system message log. It is recommended that this file always be checked after an unexpected event. Messages in this file may not always make sense to a user or DFdiscover administrator but they can be very valuable to a DFdiscover support person.

UNIX permissions are a common source of problems within DFdiscover. If a problem occurs with a DFdiscover executable, one can easily determine whether or not permissions are a cause of (or contributor to) the problem. As user datafax, re-run the problematic executable, repeating the steps that led to the problem. If the problem is not repeatable, then permissions are likely a cause of the problem.

To verify the DFdiscover permissions for a study, use the DFstudyPerms utility. This application has the following usage:

% /opt/dfdiscover/utils/DFstudyPerms [-f] [-g group] #

where -f instructs the utility to fix any problems that it finds, and -g group indicates the group name for the study, which is required when the group name is not the default studies.

To restore the DFdiscover permissions that were applied to the software at the time that it was installed, re-run the SETPERMS script that is part of the DFdiscover software and can be located in the /opt/dfdiscover directory.

All of the DFdiscover shell scripts are relatively quiet during their execution. They echo the occasional message. To make the shell script very verbose, add the statement:

set -x

as the second line of any existing shell script. Re-run the shell script and watch all of the output go by!

Attempts to start client applications for a particular study database cause a Study server not running on local network message to appear on the user's screen.

The utility application DFstudyDiag must be run with -s #, where # is the DFdiscover study number, to determine the reason that the study server cannot be started. Example 13.1, “Using DFstudyDiag to evaluate the status of a study server” illustrates use of DFstudyDiag on study 248.

# /opt/dfdiscover/utils/DFstudyDiag -s 248

Diagnosing study server 248 starting Tue May  8 12:12:25 2018...
>> Trying to contact study server directly...
<< Failed.
>> Trying to load studies database from master...
<< OK.
>> Contacting portmapper on candidate hosts...
<< OK.
>> Contacting slaves on candidate hosts...
<< OK.
>> Checking portmapper entries on candidate hosts...
<< OK.
>> Looking for existing serverstatus file...
<< The file '/opt/dfdiscover/work/.serverstatus248' exists although no study
server
<< appears to be running.  The file should be removed.
Please show this output to your DFdiscover administrator.

The output will include instructions for resolving the problem.

The incoming fax daemons process incoming faxes in their own separate work directories (configured using DFadmin - Incoming). When a fax has been completely processed the fax page images are moved to either the study CRF pages directory or to the unidentified router. Thus if you find any pages remaining in an incoming daemon work directory after it has exited, something has gone wrong.

This situation may be brought to your attention by a user who indicates that 1 or more pages of a received fax appear to be missing or misplaced. They might report that in validating the data records for a new fax, they can get the first few pages to come up in DFexplore, but the last pages cannot be located. There are messages in the errors file similar to the following:

/opt/dfdiscover/work/001/1732: File exists

This message is a symptom that a previous DFinbound.rpc process terminated before completing the processing of a fax.

The application starts after the arrival of a new fax and exits when processing of the fax is complete. During this processing, DFinbound.rpc creates and manages several intermediate versions of fax image files, routing each of them before completion so that the work directory is always empty when it exits (it should also be empty before it starts). If DFinbound.rpc is terminated in-progress then it is possible for one or more intermediate files to be left behind. The next time that the DFinbound.rpc application processes a document in that working directory it notices that it is not empty and attempts to clean up the remaining files. In general, no action is required (other than to wait until the next fax is processed) to recover from this situation.

The above scenario describes what occurs when a DFdiscover incoming daemon discovers that there is insufficient disk space available to process a fax. In that case, all incoming transmissions are left in the incoming directory defined by your HylaFAX configuration. If the problem is left uncorrected for a period of time such that the filesystem containing the incoming directory also fills, then the problem will escalate to the HylaFAX level. At the HylaFAX level, the HylaFAX software will no longer answer any incoming calls. This is now a serious situation as investigators will no longer be able to transmit case report forms to your site.

To correct this problem, you must first resolve the DFdiscover filesystem problems that were detected. Follow the steps described above to accomplish this. When these steps are completed the filesystem containing the incoming directory should no longer be at 100% capacity. The next incoming call will be answered by a fax modem and your operation will return to a normal state.

There are two situations where auto logout can occur, one expected and one unexpected:

In both instances, the user will be logged out without saving any changes. For this reason, users are encouraged to save changes regularly and never leave a client application unattended.

Following an auto logout, the user will be notified on next login that their application auto logged out during its last use and when that occurred.

If a DFdiscover server (master or study database) does not respond to a DFadmin request within sixty seconds, a dialog will appear indicating that there has been no response from the DFdiscover server. If the suspects that the lengthy delay is a result of network congestion, the user can choose to wait until sixty seconds has elapsed. Otherwise, the user can exit the application (any unsaved changes will be lost).