Apollo: No debug info in Apollo 6

[glebkiselev]

I tried to start publishing debug info in the terminal or planning.INFO file using previous issues describing debug behavior. I add --use_navigation_mode --v=4 and --vmodule=piecewise_jerk_path_optimizer=4 in planning.conf inside the docker, but no messages were published.
How to fix this problem?

[daohu527]

Reason

I suggest use GLOG_v=4 instead -v or --vmodule.

If the Google gflags library isn't installed, you set flags via environment variables, prefixing the flag name with "GLOG_", e.g.

If you add gflag in the moudule and be sure to parse the argv -v will work. The ref link

Suggestion

1. You can modify the config "DEBUG log "
   https://github.com/ApolloAuto/apollo/blob/38495c70c5a28a43630bee2c7950f16302f83690/cyber/setup.bash#L37-L46

2. Or you can run cmd with

GLOG_v=4 GLOG_logtostderr=1 ./bazel-bin/modules/planning/xxx

[glebkiselev]

After adding

export GLOG_minloglevel=-1 
export GLOG_v=4 

1. I found DEBUG lv in mainboard INFO files, but didn't find any required info in planning.INFO files. For example, I want to check

  ADEBUG << "Plan at the starting point: x = " << init_point.path_point().x()
         << ", y = " << init_point.path_point().y()
         << ", and angle = " << init_point.path_point().theta();

In file /apollo/modules/planning/tasks/optimizers/piecewise_jerk_path/piecewise_jerk_path_optimizer.cc
During the test I have ran car with route adding though Dreamviewer and lgsvl sim.

1. If I try to type inside apollo docker:

/apollo$ GLOG_v=4 GLOG_logtostderr=1 ./bazel-bin/modules/planning/tasks/optimizers/piecewise_jerk_path/piecewise_jerk_path_optimizer.cc
bash: ./bazel-bin/modules/planning/tasks/optimizers/piecewise_jerk_path/piecewise_jerk_path_optimizer.cc: No such file or directory

[daohu527]

1. Could you pls check if any other debug messages in Planning.INFO. Or could you find this log use global search in "data/log"?
2. You can only execute executable files, not .cc files. I suggest you use the first method.

[glebkiselev]

I reinstalled apollo and set all like @daohu527 told to setup.sh. After that I have no planning.INFO file exist in "data/log", but all messages are published in mainboard.INFO. There are a lot of messages and I wish to reduce their number. You have told me that I can start only 1 file debug. Can you give an example of how to debug only piecewise_jerk_path_optimizer? Or is there some way to post messages to different files ex. "piecewise_jerk_path_optimizer_debug", "borrow_decider_debug",...?

[daohu527]

1. I don’t know how you start each module, it may be related to this. It seems that the glog log can be segmented according to the module. Because I don’t have an environment now, can you describe how did you start the module?
2. There is a way to set the signal file log level, but it is not suitable for the planning module, below is an example. The planning module is start through cyber_launch, which is different from the way to start binary files, so I suggest you use the first method.

GLOG_v=4 GLOG_logtostderr=1 ./bazel-bin/modules/contrib/cyber_bridge/cyber_bridge

1. If you are only testing the piecewise_jerk_path_optimizer of a single function, you can debug by running test cases.If you are doing some complex tests, you may need to test through an simulation. If it can be tested by test cases, it will be very simple.

I suggest you try the suggestions in 1 and 3 first

[glebkiselev]

I created a .vscode/launch.json and .vscode/tasks.json files to debug the project. In the launch file I start the planning module with the following code:

{
    "version": "0.2.0",
    "configurations": [
    {
        "name": "C++ Launch",
        "type": "cppdbg",
        "request": "launch",
        "program": "/apollo/bazel-bin/cyber/mainboard",
        "args": ["-d", "/apollo/modules/planning/dag/planning.dag"],
        "stopAtEntry": true,
        "cwd": "${workspaceRoot}",
        "environment": [],
        "externalConsole": false,
        "linux": {
            "MIMode": "gdb"
        },
        "osx": {
            "MIMode": "gdb"
        },
        "windows": {
            "MIMode": "gdb"
        }
    }
    ]
}

This allows me to stop on the breaking points in planning module code (including jerk optimizer). I want to check the work of OSQP library and understand how optimization works. If I could start only goal modules in debug logging mode it becomes easier for me to check everything. Are there any OSQP descriptions in the apollo project? I am interested in the improvement of movable obstacles avoidance code.

[daohu527]

Although the correct reason is not found, please modify the following configuration in "apollo/cyber/setup.bash".

1. modify the "apollo/cyber/setup.bash"

 # for DEBUG log 
 #export GLOG_minloglevel=-1   // DO NOT ENABLE THIS!!!
 export GLOG_v=4 

1. Enable environment variables

source cyber/setup.bash

Then debug logs are printed in files.

[daohu527]

Reason

The reason may be found, you cannot set the LogSeverity to -1 (FLAGS_minloglevel == -1)
https://github.com/ApolloAuto/apollo/blob/09822f128f2bf561cc0a55589eb0d66f92c9056c/cyber/init.cc#L79-L80

If SetLogger's LogSeverity not in [0, 4], then you can't set the wrapped logger to glog. The system will use the default logger in glog, so all files will be printed in one file.

Wrapped logger

Apollo's logger do a wrap for glog and will create file for each module
https://github.com/ApolloAuto/apollo/blob/3180885692681eccfdb48198ba6fa031d8f95fb4/cyber/logger/log_file_object.cc#L146-L149

If you don't use the wrapped logger then you can't get such function.

[glebkiselev]

Is it possible to add another logging library (e.x. g3log) to do things like that:

#include <g3log/g3log.hpp>
#include <g3log/logworker.hpp>
#include <memory>

const std::string path_to_log_file = "/tmp/";
const std::string label = "testlog";

int main(int argc, char**argv) {
   using namespace g3;
   auto worker = LogWorker::createLogWorker();
   auto defaultHandler = worker->addDefaultLogger(label,
                                                 path_to_log_file);
   // logger is initialized
   g3::initializeLogging(worker.get());
   LOG(DEBUG) << "debug info";
   LOG(WARNING) << "warn info"
                << "all warn";

   g3::internal::shutDownLogging();
}

in parallel to basic glog? It will allow logging only preferable part of code with a separate logger.

[daohu527]

Of course yes.

apollo already modify the glog to be asynchronous, I don’t really understand the reason why other logs are needed. Why do we need to reinvent the wheel?

[glebkiselev]

According to your previous comment, I fixed the logging level and Apollo started printing a log by the module. But I would like to achieve an even more accurate division into files. For example, the planning module prints a log of 3746200 lines and it is not realistic to understand it. I would like to display the log of 1 file: log of planning/math/piecewise_jerk/piece_jerk_path_problem.cc where I can compare different representations of "columns" vector for example, or others.

[daohu527]

trick

There is a little trick to meet your needs. the "test" is the file name, you can change the name if you need.

ALOG_MODULE("test", INFO) << "hello world";
ALOG_MODULE("test", WARN) << "hello world";
ALOG_MODULE("test", ERROR) << "hello world";

filter

or you should filter the log by

grep shm_dispatcher.cc data/log/mainboard.INFO

[glebkiselev]

Yep, thnks! Your trick solved the problem!)