Commit 5b871459 authored by Piergiorgio Pancino's avatar Piergiorgio Pancino Committed by Matias Guijarro

Mapping and logging documentation improvement

parent 277a8364
# How to use Session map
Bliss builds a graph of instances created in the session.
This is in fact a dynamic map where every instance is a node related to other nodes.
Thanks to this map we can access instances at realtime, collect information and interact.
Let's go further with some code.
## Basic Map
```python
BLISS [1]: from bliss.common import session
BLISS [2]: m = session.get_current().map # the map
BLISS [3]: len(m)
Out [3]: 5
BLISS [4]: list(m) # list of node ids
Out [4]: ['session', 'controllers', 'comms', 'counters','axes']
BLISS [5]: m['session'] # accessing an element
Out [5]: {'instance': 'session', 'tag': 'session', '_logger': <Logger session (WARNING)>}
BLISS [6]: m.G # the DiGrap low-level container
Out [6]: <networkx.classes.digraph.DiGraph object at 0x7fdc4fa435c0>
BLISS [7]: m.G.nodes # listing directly DiGraph nodes
Out [7]: NodeView(('session', 'controllers', 'comms', 'counters','axes'))
BLISS [8]: m.draw_pygraphviz()
```
{% dot session_map_basic.svg
strict digraph {
node [label="\N"];
session;
controllers;
session -> controllers;
comms;
session -> comms;
counters;
session -> counters;
axes;
session -> axes;
}
%}
We can see that `map.G` is an instance of DiGraph from networkx module and that has a length of 5.
We can also list the names of basic nodes of a session.
## More complex map
```python
BLISS [3]: from bliss.common import session
BLISS [4]: m = session.get_current().map # the map instance
BLISS [5]: roby = config.get('roby')
BLISS [6]: len(m)
Out [6]: 7
BLISS [7]: list(m)
Out [7]: ['session', 'controllers', 'comms', 'counters', 'axes', 140483187066584, 140483253486984]
BLISS [9]: m.draw_pygraphviz()
```
{% dot session_map_complex.svg
strict digraph {
node [label="\N"];
session;
controllers;
session -> controllers;
comms;
session -> comms;
counters;
session -> counters;
axes;
session -> axes;
mockup;
controllers -> mockup;
roby;
mockup -> roby;
axes -> roby;
}
%}
After getting `roby` the map increases the size to 7. In fact, also the controller `mockup` was initialized.
## Node IDs
Going a bit more indeep about how we identify nodes we can have two tipes:
* Strings, identified by the string itself
* Other Instances, identified by python id(instance) number
## Registering nodes
In the following code we will register two nodes: the first is a `string` node, the second is an instance of a just defined class A.
You can notice some facts:
* The first argument is **the instance** that you want to register
* If it is a string the string itself (e.g. 'my_node')
* If it is an instance give it as a reference (e.g. myinst in the case above or self inside a class)
* If no parent is given the instance will be registered under "controllers"
* The return value of register is the node dictionary where we have a weakref to the instance and a logger. We can access those also through: `session.get_current().map.G[node_id]`
```python
BLISS [1]: from bliss.common import session
BLISS [2]: m = session.get_current().map
BLISS [3]: m.register('my_node')
Out [3]: {'instance': 'my_node', 'tag': 'my_node', '_logger': <Logger session.controllers.my_node (WARNING)>}
BLISS [4]: class A():
...: pass
BLISS [5]: myinst = A()
BLISS [6]: m.register(myinst, parents_list=['my_node','counters'])
Out [6]: {'instance': <weakref at 0x7fb525909318; to 'A' at 0x7fb525813da0>, '_logger': <Logger session.controllers.my_node. (WARNING)>}
BLISS [7]: m.draw_pygraphviz()
```
{% dot session_map_addnode.svg
strict digraph {
node [label="\N"];
session [ label=session, ];
controllers [ label=controllers, ];
session -> controllers;
comms [ label=comms,];
session -> comms;
counters [ label=counters,];
session -> counters;
axes;
session -> axes;
my_node [ label=my_node, ];
controllers -> my_node;
140415995035040 [ label=140415995035040];
my_node -> 140415995035040;
counters -> 140415995035040;
}
%}
Conceptually we registered the instance `a` of the `class A` as a child of my_node and counters. If we were asked for what is it, we could suppose that is a counter for my_node. Just an example anyway.
For more examples on how to register a device, see: [Logging a controller](dev_maplog_controller.md)
# Map Advanced features
The map is in fact a picture `picture` of the runtime state of the session.
Through the map we can:
* visualize the map of existing instances
* get instance references and, with this, access every method/attribute
* introspect attributes
## Visualize the map
As simple as:
```python
from bliss.common import session
session.get_current().map.draw_pygraphviz()
```
or with matplotlib:
```python
from bliss.common import session
session.get_current().map.draw_matplotlib()
```
## Introspection
You can use the same approach to introspect the map passing a specific argument:
```python
from bliss.common import session
m = session.get_current().map
# will try to visualize instance attributes 'port' and 'ip')
m.draw_pygraphviz(format_node="inst.port+inst.ip")
# will try to visualize instance 'controller' attribute as node text
m.draw_pygraphviz(format_node="inst.controller")
# will try to visualize instance 'conn' attribute and if does not exist the id
m.draw_pygraphviz(format_node="inst.conn->id")
```
This `mini language` can be used to visualize instance attributes.
We have the `+` operator that will visualize more than one attribute separated by a space
and we have the `->` operator that will define an order: try to visualize the first, if None
try to visualize the second and so on.
This kind of visualization is a high level interface intended for representing in an human
friendly way all instances.
If you need something more machine-friendly the way to go is:
```python
m = session.get_current().map
m.update_all_keys(format_string="tag->inst.name->inst.__class__->id", dict_key="label")
```
This will update a key,value pair inside the DiGraph (default key is `label`) with the values
introspected from the instance as defined by format_string.
This could be used by scripts or future modules to extract info from the graph.
More detailed information about the mini-language can be retrieved with:
```
from bliss.common import session
help(session.get_current().map.format_node)
```
## Access instance references
Instances can be accessed through the DiGraph.
```python
TEST_SESSION [16]: m = session.get_current().map
TEST_SESSION [17]: [node for node in m]
Out [16]: ['session', 'controllers', 'comms', 'counters', 'axes', 140483187066584, 140483253486984]
TEST_SESSION [10]: [m[node].get('instance') for node in m]
Out [10]: ['session', 'controllers', 'comms', 'counters', 'axes', <weakref at 0x7fc4ce6c8d18; to 'Mockup' at 0x7fc4ca7646d8>, <weakref at 0x7fc4ce6c8e08; to 'MockupAxis' at 0x7fc4ce6bc588>]
TEST_SESSION [11]: [m[node].get('name') for node in m]
Out [11]: [None, None, None, None, None, '8d6318d713ee6beb9efbb5be322b8dde', 'roby']
```
# Adding logging and mapping capabilities to Controller
To know how to use logging and mapping, see: [Shell
Logging](shell_logging.md)
To know how to use logging inside the shell, see: [Shell Logging](shell_logging.md)
To know more about mapping and how to use it, see: [Session map](dev_instance_map.md)
## Logging and Mapping
Logging and Mapping instances are strictly related in Bliss: every
device should register himself before gaining those features.
instance should register himself before gaining those features.
## How to Register a device
## How to Register an instance
```python
from bliss.common import mapping
from bliss.common import session
from bliss.common.logtools import LogMixin
class MyController(LogMixin):
def __init__(self, *args, **kwargs):
mapping.register(self)
session.get_current().map.register(self)
...
self._logger.info("HI, I am born")
```
The preceding is a barebone example of how to register a device inside
device map and send an INFO logging message.
The preceding is a barebone example of how to register an instance inside
session map and send an INFO logging message.
Key points are the following:
### Add LogMixin to the device
### Add LogMixin to the class
This will add `_logger` method to class that will be the entry point for
all logging operations and will also raise an exception if the logging
will be used before device is mapped inside bliss device map.
will be used before instance is mapped inside bliss session map.
### Register the device
### Register the instance
This is done calling `mapping.register` passing at list the self
This is done calling `session.get_current().map.register` passing at list the self
parameter. If _logger methods are used before the registration this
will fail raising an exception; for this reason mapping.register
should be called as soon as possible.
## How to Create a nice device map
## How to Create a nice session map
The map is in fact a Graph that wants to register every relevant
instance of a Beamline, including Controller, Connections, Devices,
instance of a Session, including Controller, Connections, Devices,
Axis, and so on.
When registering a device it is convenient to add as much information
When registering an instance it is convenient to add as much information
as possible in order to have an usefull map that can be used to
represent the beamline or to apply any sort of desired handler.
represent the session or to apply any sort of desired handler.
For this reason is important to add:
......@@ -58,59 +58,149 @@ For this reason is important to add:
communication it will be a controller but also "comms".
* children_list: a list containing children istances as comms,
transactions, devices, axis
* tag: this should be the best suited name to represent the instance.
* tag: this should be the best suited name to represent the instance, if not
given instance.name will be used or id of the object
Some Examples:
### Example 1:
Here we have a Motor that is child of a controller
```python
mapping.register(self, parents_list=[self.controller], tag=str(self))
# self is motor instance (we are inside Axis.axis class)
# 'name' attribute is used as default to represent the object in the map
# 'tag' can be passed as kwarg to replace the name
# default is using name attribute of class
m = session.get_current().map
m.register(self, parents_list=[self.controller])
```
{% dot session_map_basic.svg
strict digraph {
rankdir="LR";
splines=false;
session;
controllers;
controller [label="ee6beb9efb",];
axis [label="m0"]
controller -> axis;
controllers -> controller;
session -> controllers;
comms;
session -> comms;
counters;
session -> counters;
}
%}
### Example 2:
Here we have a controller with a child connection
```python
mapping.register(self, children_list=[self._cnx])
# self is test_controller
m = session.get_current().map
m.register(self, children_list=[self._cnx], tag='test controller')
```
{% dot session_map_basic.svg
strict digraph {
rankdir="LR";
splines=false;
session;
controllers;
controller [label="test controller",];
conn [label="tcp_ip"]
controller -> conn;
controllers -> controller;
session -> controllers;
comms;
session -> comms;
counters;
session -> counters;
}
%}
### Example 3:
Here we have a serial connection that we also want to be child of
"beamline"->"comms"
"session"->"comms"
```python
mapping.register(self, parents_list=["comms"])
# registering m0, this normally is automatic, just as an example
# first passage we register m0, the controller and the connection
m = session.get_current().map
m.register(m0, parent_list=[m0.controller])
# in the second passage we register the TCP connection as a child of
# m0 and of comms
m = session.get_current().map
m.register(m0.conn, parent_list=[m0.controller, 'comms'])
```
{% dot session_map_basic.svg
strict digraph {
rankdir="LR";
splines=false;
session;
controllers;
session -> controllers;
comms;
session -> comms;
counters;
session -> counters;
controller;
controllers -> controller;
m0;
controller -> m0;
tcp;
controller -> tcp;
comms -> tcp;
}
%}
### Example 4:
To explain the flexibility here we are mapping inside a Command class
(that is self) and `self._fd` is a child socket, in fact we are inside
Command but we are recording all links beetween them. The result will
something like this:
In fact, instances that will not have parents will be childs of
"session"->"controllers" by default and later eventually remapped if we
register another instance as parent of `Command`.
```python
from bliss.common import session
m = session.get_current().map
self._fd = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
m.register(self._fd, parents_list=[self, "comms"], tag=f"Socket[{local_host}:{local_port}",
```
{% dot devices_mapping.svg
digraph devices_mapping{
rankdir="LR";
splines=false;
bl [label="beamline", shape="box"];
dev [label="devices", shape="box"];
cmd [label="Command", shape="box"];
sock [label="Socket", shape="box"];
session;
controllers;
session -> controllers;
comms;
session -> comms;
counters;
session -> counters;
command;
controllers -> command;
sock [label="Socket[localhost:47319]"];
command -> sock;
comms -> sock;
bl -> dev;
dev -> cmd;
cmd -> sock;
bl -> sock;
}
%}
In fact, instances that will not have parents will be childs of
"beamline"->"devices" by default and later eventually remapped if we
register another instance as parent of `Command`.
```python
self._fd = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
mapping.register(self._fd, parents_list=[self, "comms"], tag=f"Socket[{local_host}:{local_port}",
```
### Final Considerations:
There is no problem if you want to register the same device twice or
There is no problem if you want to register the same instance twice or
even more times: it will automatically remap adding or removing links
if necessary. In general this is convenient for example when you want
to log as soon as possible and then after creating let's say a Socket
......@@ -118,20 +208,72 @@ you want to register it a child.
The Bliss barebone map is something like this:
```
beamline -> devices
-> sessions
-> comms
-> counters
```
{% dot session_map_basic.svg
strict digraph {
node [label="\N"];
session;
controllers;'
session -> controllers;
comms;
session -> comms;
counters;
session -> counters;
}
%}
Those Graph nodes are in fact string and they constitute the root to
wich all other nodes will be attached.
Be aware that all instances, if nothing is specify, will be child of
devices.
controllers.
## Logging Instance Methods
TODO
Every instance that inherits from LogMixin and is registered gains a _logger instance that is in fact a python logging.Logger instance with some more powers.
This means that you will find a ._logger attribute attached to your instance that you can use to send messages and configure logging.
The most useful methods are:
* .debugon()
* .debugoff()
* .debug_data(message, data)
* .set_ascii_format()
* .set_hex_format()
### .debugon() and .debugoff()
Simply to set logging level to DEBUG or reset to default level.
### .debug_data, .set_ascii_format, .set_hex_format
The purpose of debug_data is to have a convenient way to debug aggregate data like string, bytestrings and dictionary. This is helpful for hardware comunication.
The first argument of debug_data is the user-readable message, the second is a string, bytestring or a dictionary.
set_ascii_format and set_hex_format methods allows to change the representation of data at runtime.
Let's do some examples:
### Passing a dictionary to debug_data:
```python
T_SESSION [14]: m0._logger.debug_data('Machine connection settings',{'ip':'10.81.0.23','hostname':'wcid00b'})
DEBUG 2019-05-17 14:58:27,861 session.controllers.8d6318d713.axis.m0: Machine connection settings ip=10.81.0.23 ; hostname=wcid00b
```
### Simulating a message sent from `m0`.
Check how debug_data works and how we can change format from ascii to hex and viceversa, this can be done at runtime.
```python
TEST_SESSION [1]: m0._logger.debugon()
TEST_SESSION [2]: raw_msg = bytes([0,2,3,12,254,255,232,121,123,83,72])
TEST_SESSION [3]: m0._logger.set_ascii_format()
TEST_SESSION [4]: m0._logger.debug_data('Sending Data',raw_msg)
DEBUG 2019-05-17 15:24:26,231 session.controllers.8d6318d.axis.m0: Sending Data bytes=11 b'\x00\x02\x03\x0c\xfe\xff\xe8y{SH'
TEST_SESSION [5]: m0._logger.set_hex_format()
TEST_SESSION [6]: m0._logger.debug_data('Sending Data',raw_msg)
DEBUG 2019-05-17 15:24:34,731 session.controllers.8d6318d.axis.m0: Sending Data bytes=11 \x00\x02\x03\x0c\xfe\xff\xe8\x79\x7b\x53\x48
```
......@@ -7,20 +7,30 @@ There are two kind of logging in Bliss:
* *Module logging*
* *Instance logging*
more info about [Python logging module](https://docs.python.org/3/library/logging.html).
### Module logging
We can have a look at both with `lslog()`.
Module logging is the standard python "way of logging" in which every
*logger* has the same name that the python module which is producing
it.
```python
DEMO [2]: lslog()
The hierarchy is given by the files organization inside the Bliss
project folder.
BLISS MODULE LOGGERS
module level set
==================== ======== =====
bliss WARNING YES
bliss.config WARNING -
bliss.common.mapping WARNING -
bliss.scans WARNING -
bliss.shell WARNING -
bliss.standard WARNING -
`lslog()` allows to see the list of loggers in use.
BEAMLINE INSTANCE MAP LOGGERS
instance level set
================================================= ======== =====
beamline WARNING YES
beamline.comms WARNING -
beamline.counters WARNING -
beamline.devices WARNING -
beamline.sessions WARNING -
```
The relevant informations are:
......@@ -38,6 +48,17 @@ The relevant informations are:
* `-` if the level is inherited from the upper level
more info about [Python logging module](https://docs.python.org/3/library/logging.html).
### Module logging
Module-level logging is the standard python "way of logging" in which every
*logger* has the same name as the python module producing it.
The hierarchy is given by files organization inside Bliss project folder.
```python
DEMO [2]: lslog()
......@@ -53,11 +74,17 @@ bliss.standard WARNING -
...
```
Inside modules logger object are instantiated with the well known:
```python
import logging
logger = logging.getLogger(__name__)
```
Thiss will create a logger with a name that will be a commad separated folder/file name hierarchy.
### Instance logging
Same remarks for Instance logging which is a specific Bliss logging in
which every logger has a name that represents the instance hierarchy.
Instance-level logging allows to discriminate beetween different instances of the same class. With instance logging every device or instance has his own logger with a name that represents the conceptual hierarchy of the hardware/software stack.
```
DEMO [2]: lslog()
......@@ -92,8 +119,15 @@ beamline.sessions WARNING -
### Devices and instances
Probably the most convenient way to activate logging for a specific
device is from the `_logger` method of the device itself:
Activate logging can be done as following:
```
TEST_SESSION [1]: debugon('*s1d') # using glob pattern
NO bliss loggers found for [*s1d]
Set logger [beamline.devices.8d6318d713ee6be.axis.s1d] to DEBUG level
```
Or within the device itself:
```
BLISS [1]: m0 = config.get('m0')
......@@ -125,18 +159,32 @@ Activating debug from one specific device may not give the desired
informations as a device could be managed by a controller and a
controller may handle a communication.
To collect all informations activate debug at the higher level,
usually for the controller.
Sometimes what you will probably need is to activate debug from the controller level.
```
log.debugon('8d6318d7dde')
TEST_SESSION [4]: debugon('*8d6318d7*')
NO bliss loggers found for [*8d6318d7*]
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.hooked_error_m0] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.hooked_m0] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.hooked_m1] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.jogger] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.m0] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.m1] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.m2] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.omega] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.roby] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.s1b] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.s1d] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.s1f] to DEBUG level
Set logger [beamline.devices.8d6318d713ee6beb9efbb5be322b8dde.axis.s1u] to DEBUG level
```
## log commands
The class container for log commands.
The class instance for log commands.
### log.lslog() or lslog()
### lslog()
`lslog("glob name")`
......@@ -188,7 +236,7 @@ instance level set
beamline.comms WARNING -
```
### log.lsdebug() or lsdebug()
### lsdebug()
`lsdebug()` shows loggers currently in debug mode:
......@@ -203,37 +251,81 @@ instance level set
beamline.counters DEBUG YES
```
### log.debugon()
### debugon()
```
debugon("globname")
```
`log.debugon("logger name or part of it")` activates debug for a
specific logger name, it will match also if is only a part of the
logger name is given.
Activates debug for a specific logger name using glob pattern.
```pyton
BLISS [22]: log.debugon('hooked')
```python
BLISS [22]: debugon('*hooked')
NO bliss loggers found for [hooked]
Set logger [beamline.devices.8d6318d7dde.axis.hooked_error_m0] to DEBUG level
Set logger [beamline.devices.8d6318d7dde.axis.hooked_m0] to DEBUG level
Set logger [beamline.devices.8d6318d7dde.axis.hooked_m1] to DEBUG level
```
### log.debugoff()
### debugoff()
```
log.debugoff("logger name or part of it")
debugoff("globname")
```
Like `debugon()` but sets the logging level for that logger name to
the global defined one.
Like `debugon()` but sets the logging level to global defined one.
```
BLISS [23]: log.debugoff('hooked')
BLISS [23]: debugoff('*hooked*')
NO bliss loggers found for [hooked]
Remove DEBUG level from logger [beamline.devices.8d6318d7de.axis.hooked_error_m0]
Remove DEBUG level from logger [beamline.devices.8d6318d7de.axis.hooked_m0]
Remove DEBUG level from logger [beamline.devices.8d6318d7de.axis.hooked_m1]
```
For details on how to implement logging in a Bliss module or
controller, see: [mapping and logging](dev_maplog_controller.md)
## How to log user shell commands
It is only a matter of activating the proper logger: bliss.shell.cli.repl
```python
BLISS [2]: debugon('bliss.shell.cli.repl')
Set logger [bliss.shell.cli.repl] to DEBUG level
NO map loggers found for [bliss.shell.cli.repl]
BLISS [3]: print('LogMe')
DEBUG 2019-05-17 13:09:32,628 bliss.shell.cli.repl: USER INPUT: print('LogMe')
LogMe
```
## Save log to File or other destinations
There are a lot of ways to accomplish this.
The easiest is to add a logging Handler to the root Logger.
This is accomplished using a normal python logging Handler taken from the standard library.
Logging could be initialized on bliss shell, but probably the best place to do this is in session configuration script.
```python
# Just near the end of your session_setup.py