ROS Resources: Documentation | Support | Discussion Forum | Index | Service Status | ros @ Robotics Stack Exchange
Ask Your Question
1

How to simplify massive numbers of log files

asked 2018-01-02 08:38:04 -0500

Cerin gravatar image

How do you simplify ROS's logging system so it doesn't generate a massive number of log files?

I'm trying to diagnose a problem with a specific node crashing upon launch. So, the first thing I want to check is its logging output. Sounds simple, right? Unfortunately, it's quite a headache. I went to the default log directory in ~/.ros/log and I see:

image description

What in the world is this? I have, maybe, 6 nodes running. Why are so many log files necessary? Where do I begin to find the one containing output from my node?

If this is the default, how do I override this so either:

  1. everything goes to a single easily searchable log file?
  2. name the log files by the name of the node that writes to them, instead of some meaningless UUID?
edit retag flag offensive close merge delete

Comments

2

Cut-and-paste text instead of screenshots of text is a lot easier to read and analyze.

lucasw gravatar image lucasw  ( 2018-01-02 11:17:42 -0500 )edit

You want me to cut and paste the ls output showing the thousands of random log file names? How would that help you? Normally I'd agree that copy and paste is better, but not in this instance.

Cerin gravatar image Cerin  ( 2018-01-02 11:20:55 -0500 )edit
1

Just capture about a screens worth of output, it could be exactly what is in the existing image except text, or less since it will be a bit bigger due to font size. A ... at the end could be added to say there is more output that has been excluded.

lucasw gravatar image lucasw  ( 2018-01-02 12:26:57 -0500 )edit

Just an observation: from the screenshot it appears that someone/something is invoking rosservice (the command line utility) about every 7 or 8 seconds. As @mig already explained, each invocation will result in a log file. That would seem to be the primary cause of the many log files.

gvdhoorn gravatar image gvdhoorn  ( 2018-01-05 04:33:44 -0500 )edit

2 Answers

Sort by ยป oldest newest most voted
0

answered 2018-01-05 09:16:17 -0500

Cerin gravatar image

I was using robot_upstart to launch my all.launch, and apparently this package is still very buggy and unstable in 16.04, and no longer outputs any logging information to its documented upstart log file. I replaced this with supervisor, and my all.launch now works perfectly.

edit flag offensive delete link more

Comments

For the honor of robot_upstart, I use it at the production system dev for years and have never seen the issue like you described in the OP. I understand your frustration, and I have no way to disagree with your observation, but if you claim an OSS package to be "buggy" and "unstable", I'd much appreciate providing more concrete analysis.

130s gravatar image 130s  ( 2020-03-31 20:51:45 -0500 )edit
0

answered 2018-01-05 01:07:58 -0500

mgruhler gravatar image

First of all, by default, all log files of one specific ROS run (i.e. as long as one rosmaster is up) go into a subdirectory in ~/.ros/logs/ that contains a UUID. At least in kinetic on 16.04, there is a symlink called latest to the latest created log directory. Also, the log files get named by the node name (not the node type name). The above obviously is for the default configuration.

What can be seen from your screenshot is only (thus, seconding @lucasw) that you did a lot of manually calling rostopic <something> and rosservice <something>. In the end, each of those creates a new node, publishing/subscribing/calling, and closing it again immediately.

Easiest way: call a rosclean purge, cleaning your log directory, and then reproduce the problem.

Note though, that if this is simply a crash, e.g. a segfault, it is also highly likely that the log file is just empty...

edit flag offensive delete link more

Comments

it is also highly likely that the log file is just empty...

Yes, I expect this as well.

@Cerin: debugging a crashing node is infinitely easier with gdb than looking at log files. See Roslaunch Nodes in GDB.

gvdhoorn gravatar image gvdhoorn  ( 2018-01-05 02:39:13 -0500 )edit

I've manually run rostopic and rosservice a few times, but not the thousands for all the UUID log files I'm seeing. If a named node listens of publishes to a topic, or calls a service, should that create one of these UUID log files too?

Cerin gravatar image Cerin  ( 2018-01-05 09:18:52 -0500 )edit

A new logfile is created for every new node that you start. The uuid is bound to the lifetime of a rosmaster.

To be clear: the nrs in the logs in your screenshot (the rosservice_...log ones) are unix timestamps, not uuids.

gvdhoorn gravatar image gvdhoorn  ( 2018-01-05 09:23:57 -0500 )edit

So how do I stop these from being created in separate files, or at least get them named to reflect the node/rostopic/rosservice calls that created them. As is, these log files are completely useless.

Cerin gravatar image Cerin  ( 2018-01-05 10:20:20 -0500 )edit
1

They are not completely useless, and I would appreciate it if we can keep this constructive.

The filename is generated here. There is no automated way right now, afaik, to ..

gvdhoorn gravatar image gvdhoorn  ( 2018-01-05 10:33:07 -0500 )edit

.. configure 'something' to generate filenames like you suggest (including command line args).

It could be done though, as any node that is passed the __log remapping argument will use whatever value is associated with it for a filename.

gvdhoorn gravatar image gvdhoorn  ( 2018-01-05 10:34:12 -0500 )edit

Also: how would you like the filename to be set for services/topics that are more complex than a single line of args (which would be just about anything that is not a toy example)? We could serialise the entire yaml contents of the request/msg, but that will lead to very long filenames.

gvdhoorn gravatar image gvdhoorn  ( 2018-01-05 10:35:54 -0500 )edit

The filename is generated here

for rospy, that is.

If using roslaunch or rosrun, the __log remapping is always supplied, otherwise the code generates a filename.

gvdhoorn gravatar image gvdhoorn  ( 2018-01-05 10:37:49 -0500 )edit

Question Tools

2 followers

Stats

Asked: 2018-01-02 08:38:04 -0500

Seen: 1,132 times

Last updated: Jan 05 '18