Logs

Every MooseFS module reports what it is doing to the system log of the machine that it runs on. This page covers where those messages go and what you can set about them. The page also covers how one line is built and which messages to recognize on sight.

Modules write to the system log, never a file

A MooseFS module has two outlets for a message: the system log through syslog(3), and standard error. No module opens a log file of its own, so there is no file to tail and no directory to point a collector at. A module's messages go into the system log of its machine, among the messages of every other daemon there. The one exception is the separate Windows Client PRO (PRO Edition only), which reports to the Windows Event Log.

The syslog facility that a module writes to depends on how the module was started. A module started with the start action goes into the background and logs to daemon. The packaged service units also run the module this way. A module kept in the foreground logs to user. The same module therefore matches a different branch of the collector's rules, depending on which of the two ways you chose.

The identifier in front names the module

A line from a MooseFS module has this shape, where angle brackets represent values:

<date> <host> mfsmaster[<pid>]: [notice] internal state change ELECT->LEADER

The date, the host, and the layout around them come from the system log. MooseFS supplies the identifier, the process ID, the level in square brackets, and the message itself. The process ID is in every line.

The identifier is the value of SYSLOG_IDENT. Its default is the name of the program: mfsmaster, mfschunkserver, mfsmetalogger, and mfsgui. A client cannot set the identifier. mfsmount always logs as mfsmount. The block device client logs as mfsblockdev. The packaged service units do not override the identifier. Filter on the identifier when you want the messages of one module out of the whole system log. On a machine whose system log is kept by journald:

journalctl -t mfsmaster

A failed start or mount reports to the terminal

While a module starts, it writes to both outlets at once: the system log and the terminal of the command that started it. The process that goes into the background keeps a channel open to that command until initialization ends. The process closes that channel right after <ident> daemon initialized properly. From then on, the system log is the only outlet. A module that never reaches that line has already logged the reason in the system log. Most of what the module logged also reaches the terminal of the start command, so that terminal is the fastest place to look. Only the messages that a module writes before it opens the system log are on the terminal alone. One of them is can't load config file: <path> - using defaults.

-f keeps the module in the foreground instead: every message goes to standard error for the whole run. The facility becomes user. On a terminal, the levels are colored, but a redirected stream gets plain text. -v is not a verbosity switch. It prints the version and exits.

The client behaves the same way for a reason of its own. mfsmount opens the system log only after it has reached the Master Server. Everything that the mounting phase reports, a refused mount included, therefore appears on the terminal of the mount command. A mount that succeeds stops writing to that terminal and reports to the system log from then on. A failed mount is reported on the terminal. A mount that broke later is reported in the log.

The configuration file sets what a module logs

The configuration file of every server module sets the identifier, the lowest level that is logged, and the level that lower levels are raised to, each with its default. These files are mfsmaster.cfg, mfschunkserver.cfg, mfsmetalogger.cfg, and mfsgui.cfg.

• SYSLOG_IDENT names the module in the log. Default: the name of the program. This is a startup option, so a restart applies a change. An empty value falls back to the program name instead of clearing the field. Set the identifier when two instances of one module run on the same machine and you have to tell their lines apart.
• SYSLOG_MIN_LEVEL sets the lowest level that is logged at all. Default: INFO, which drops debug and keeps the rest. A message under the threshold is dropped before it is formatted, so the threshold limits standard error together with the system log. SYSLOG_MIN_LEVEL is a runtime option, applied by a reload. Only this option changes how much a module writes.
• SYSLOG_ELEVATE_TO raises the numeric priority that the module passes to the system log for messages below the set level. The option changes nothing else. Default: NOTICE, so info and debug reach the system log as notice. The level in square brackets stays the level that MooseFS assigned. Raise this level when the collector on the machine discards low priorities and you want to keep those messages anyway. SYSLOG_ELEVATE_TO is a runtime option too.

Both level options accept DEBUG, INFO, NOTICE, WARNING, and ERROR in any letter case. An unambiguous prefix is enough, so D, I, N, W, and E work as well. A value that the module cannot parse does not stop the module. At startup, the module logs error parsing SYSLOG_MIN_LEVEL option - using INFO and uses the default. On a reload, the module logs error parsing SYSLOG_MIN_LEVEL option - left unchanged and keeps the threshold that it already had.

To lower the threshold for one run without editing the file, override the option on the command line or in the environment. The override takes effect only on a fresh start, so stop the module first. A module that is already running refuses the command with can't start: lockfile is already locked by another process. The command line takes precedence over the environment, and both take precedence over the configuration file:

mfschunkserver -o SYSLOG_MIN_LEVEL=DEBUG -f start

-u has a different purpose: it logs a config: using default value for option '<name>' - '<value>' line for every option that the file leaves unset. That output shows the values that a module is running with.

The client has its own pair of level options, given as mount options: -o mfslogminlevel (default INFO) and -o mfslogelevateto (default NOTICE). Both are listed with the other mount options that mfsmount accepts.

The level separates progress from failure

Level	What it means
error	Something went wrong that the module cannot work past. It usually ends its work.
warning	Something went wrong and the module kept running.
notice	Something happened that is worth noticing. The module coped with it.
info	Ordinary progress.
debug	Detail for diagnosis. The default threshold drops it.

An error is the level that has to reach a person, because the module is stopping. Read a notice in relation to how busy the module is. The same line once an hour and once a second do not mean the same thing.

Messages worth recognizing

Each message here is quoted as the module writes it. Angle brackets represent a value in the line: an address, a path, a count, a duration.

A module starts and stops

Message	What it means
initializing <ident> modules ...	The configuration was read and the modules are coming up.
<ident> daemon initialized properly	The start succeeded. The terminal channel closes here.
error occurred during initialization - exiting	The start failed. The reason is in the lines before it, in the system log and usually on the terminal of the start command.
can't load config file: <path> - using defaults	The configuration file was not found and the module is running on defaults. Check the path if that was not your intention.
bad definition in config file '<path>': <line>	A line of the configuration file could not be parsed and was skipped.
exited from main loop	The process left its main loop and is shutting down.
exiting ...	Shutdown is under way. Up to 5.1.0 the module printed exititng ....
process exited successfully (status:0)	The process finished its shutdown cleanly.

A Master Server changes role

Where several Master Servers PRO (PRO Edition only) pass the Leader role between themselves, the server whose state changes logs every change as a notice. The leader election page covers what the states mean and how they are assigned.

Message	What it means
internal state change ELECT->LEADER	This server took the Leader role.
internal state change ELECT->DEPUTY	This server took the Deputy role while the election was under way.
internal state change LEADER->FOLLOWER(SYNCED)	This server gave up the Leader role and is a synchronized Follower again.
internal state change DEPUTY->FOLLOWER(SYNCED)	This server gave up the Deputy role.
internal state change FOLLOWER(SYNCED)->USURPER	This server is claiming the Leader role back.
state: <state> ; changed <n> seconds ago ; forceflag:<n> ; leaderip: <address>	The state this server holds now, and the Leader it sees.
state: transition <from> -> <to> ; changed <n> seconds ago ; forceflag: <n> ; leaderip: <address>	The server is between two states.

A Chunkserver drops out and comes back

The Master Server identifies the Chunkserver by address in each of its lines. The Chunkserver reports the same connection from its own side, in the system log of its own machine.

Message	What it means
chunkserver <address> register begin, usedspace: <bytes> (<n> GiB), totalspace: <bytes> (<n> GiB)	A Chunkserver started registering and reported its space.
chunkserver <address> register end	The registration finished and the server is in service.
chunkserver <address> graceful disconnection	The Chunkserver announced its stop before leaving. This is a planned stop.
chunkserver <address> disconnected, usedspace: <bytes> (<n> GiB), totalspace: <bytes> (<n> GiB)	The connection ended without an announcement. Every stop that was not announced looks like this.
chunkserver connected using localhost (<address>) - you cannot use localhost for communication between chunkserver and master	A Chunkserver registered from a loopback address. Give it an address the rest of the cluster can reach. A 5.1.0 Chunkserver refuses a loopback address for the Master Server before it registers, so the line arrives only from a Chunkserver that does not make that check.
CSTOMA_REGISTER (BEGIN,<address>): access denied - check password	The Chunkserver did not present the password the Master Server expects.
CSTOMA_REGISTER: chunkserver <address> is too old	The Chunkserver runs a version this Master Server does not accept.
connecting ...	The Chunkserver is trying to reach the Master Server.
connected to Master	The Chunkserver has a connection again.
connection timed out	The attempt to reach the Master Server ran out of time.
connection was reset by Master	The Master Server dropped the connection.
sending unregister command ...	The Chunkserver is announcing its own stop.

A disk goes bad

A disk is marked damaged once it produces more than HDD_ERROR_TOLERANCE_COUNT errors within HDD_ERROR_TOLERANCE_PERIOD seconds, both set in mfschunkserver.cfg. From that moment, the copies that the disk holds stop counting toward redundancy.

Message	What it means
hdd space manager: folder <path> will be scanned	The Chunkserver is about to scan a disk it was given.
scanning folder <path>: complete (<n>s)	The scan of that disk finished.
hdd space manager: data folder '<path>' already locked (used by another process)	The data directory is locked by another process. Look for a second process pointed at the same path.
<n> errors occurred in <n> seconds on folder: <path>	The disk crossed the error tolerance and is now damaged. Look at the disk.
disk: <path> ; statvfs error (<error>) - mark it as damaged	The Chunkserver could not read the disk's free space and marked it damaged.
disk: <path> ; unit read-only flag has been changed (RW->RO) - mark it as damaged	The disk turned read-only underneath the Chunkserver.
read_block_from_chunk: file: <path> ; block: <n> - crc error (data crc: <crc> ; check crc: <crc>)	A block read back different from what its checksum says.
write_block_to_chunk: file: <path> ; block: <n> - write error	A write into a chunk file failed.
stalled job '<job>' on chunk <id> detected	A disk operation has been running for over ten minutes. The disk is overloaded or failing.
hdd_chunk_get: serious internal data structure inconsistency - can't remove chunk <id>	The Chunkserver hit an inconsistency in its own data structures rather than a fault on the disk.

The Master Server saves metadata

Message	What it means
store process has finished - store time: <n> seconds	A metadata dump was written. This is the ordinary line of a healthy Master Server.
store process has finished - unknown store time	The dump was written and the duration could not be measured.
store process has been killed due to leadership change or termination	A save in progress was abandoned because the role changed or the server is stopping.
previous metadata save process hasn't finished yet - do not start another one	A save was still running when the next save came due. Saves are taking longer than the interval between them.
metadata not stored !!! (child exited) - exiting	The saving subprocess died, no dump was written, and the Master Server ends its work.
metadata stored in emergency mode (in non-standard location) - exiting	The dump could not go where it belongs and was written elsewhere. The Master Server ends its work.
metadata file stored in emergency mode, file name: <path>	Names the file an emergency dump went to.
fork error (store data in foreground - it will block master for a while - check /proc/sys/vm/overcommit_memory and if necessary set to 1)	The Master Server could not fork for the save and is writing in the foreground. The Master Server stays blocked until that write finishes.
no meta backup servers connected !!! - deploy backup master servers	No Follower PRO (PRO Edition only) and no Metalogger is connected, so nothing is receiving the changelog as it is written. The Community Edition line for the same state is no metaloggers connected !!!.
only metaloggers connected !!! - deploy backup master servers	Metaloggers PRO (PRO Edition only) are receiving the changelog, but no Follower is, so no server can take over the Leader's role.

Rotation belongs to whatever collects the system log

MooseFS rotates nothing and installs no logrotate configuration. The packages place no file in /etc/logrotate.d. MooseFS has nothing of its own to rotate, because every message goes out through the system log. The service that keeps the system log therefore controls the size and the retention of what a module writes. That service applies the same rules as to every other daemon on that machine.

Despite its name, BACK_LOGS is not part of log rotation. The option sets how many changelog files the Master Server keeps: the files named changelog.*.mfs. Those files contain metadata operations, not log messages.

The system log is not the only record

The operations log of a client is a separate record. This record lists the file system operations that a mount performs, and you read it from the mount itself, not from the system log. The operations log is described with the other diagnostic tools.

When you have a symptom rather than a message, work from the symptom you can see.