Debugging XenServer Using Events or Logs
Note: Some information contained in here is version specific. While we strive to ensure content on xenserver.org represents that which corresponds to XenServer 6.2 and later, the nature of the content on this page demands we include earlier versions.
Watching XAPI calls
Some users, especially developers building products using the XenServer SDK/APIs or writing complex administration scripts may be interested in watching XAPI events for debug. Events such as the Event object as you'd see in our code example:
http://docs.vmd.citrix.com/XenServer/4.0.1/api/client-examples/python/watch-all-events.py.html The recommended event watching mechanism used to be the event.next API as used in this example. If you want to incorporate event monitoring in your product we would recommend you use the API functions associated with the Event class.
We no longer recommend the event.next API for new uses and recommend that customers use the later and more powerful event.from API. For a fuller explanation plus code example, please read here.
Debugging using log files
XAPI events may be logged/recorded in the logs e.g. xensource.log (/var/log/xensource.log ) and audit.log.
The format of these logs may change between versions and they should not be regarded as a controlled interface on which to build a version independent product. The date format has recently changed (XS6.1), xensource.log now uses a more standard syslog format and the timestamp has been changed. All applications implementing event analysis should use the event.from API and should not rely on the logs or their format.
Log file overview
These are the key files required for debugging. The /var/log contains all the logging of the various subsystems. All the logs are rotated after they have reached a certain size. Hence xensource.log is the most recent log while xensource.log.1 is one rotation back and so on.
Xensource.log: This is the log written into by xapi. It is verbose so you it would be extremely tedious to wade through unless you know what you are looking for.
20120509 01:17:16.191|debug|tmdoclxb|527318 inet_rpc|dispatch:VM.start D:0912591fbb6e|dispatcher] VM.start
20120509 01:17:16.191: Timestamp of the log entry.
Note: All the Xensource logs are in UTC time while all other logs are in local time. This has been changed in XS6.1 but all previous versions will involve calculating the time difference! The format of the timestamp has also changed between XS 6.0.2 and 6.1.
debug: This indicates the level of logging.
There are 4 levels of logging: debug , info , warn and error.
tmdoclxb: Refers the host name.
527318: Refers to the thread id. It can be used most effectively to trace the operations performed by the particular thread across various log rotated logs.
D:0912591fbb6e : Is the session id of that particular action being performed. This id will propagate till the end of the session. D: Session id is a dummy session id and does not exist in the xapi database, while R: Session id is the Real session id and exists in the xapi-db.
dispatcher: It is the module from which this message is being logged. Each module performs a different function in this case dispatcher is called when the master needs to transmit commands to another host.
VM.start: Is the message logged by the particular calling function.
Xensource.log is the entry point for most debugging activities as all the chatter from xapi is logged here. Note that the pre-Tampa versions the timestamp for the all other logs except Xensource.log are in local time so you would have to calculate the time difference from the UTC timestamp of Xensource.log to find the corresponding entry in the other logs.
messages: Contains all the low level logging such as the interaction with the qemu , tapdisk e.tc basically the linux syslog messages.
Note: Xapi also logs to messages for all entries which are warn and above (warn and error) hence it is a good place to start to narrow down the error messages from xapi and then match the corresponding entry in xensource.log to investigate further.
audit: The audit logs contain any API calls that cause side effects (i.e set values e.tc.). For example SR.set_physical_size would change set the physical size of a particular SR and would hence be logged into audit.log.
SMlog: The storage component logs into the SMlog.