Launch Node from code spawns node 2 times and breaks output
Hi,
I'm a bit confused. When I try to launch my nav_stack.lauch from my benchmarking code for evaluation purposes and trying to parse the output of it, the output stops. I launch the node via execl and redirect the output to a file that gets later parsed. My call to start the node boils down to:
execl("/bin/bash", "/bin/bash", "-c", "/usr/bin/python /opt/ros/hydro/bin/roslaunch gki_3dnav_benchmark nonenav_stack.launch 2>&1 > navstackoutput.txt", NULL);
When I call the makeplan service from the same code I do get a valid response. But when I take look at the navstackoutput.txt
there's no trace of a request getting handled. Here the ouput of ps ax | grep nav_stack
:
24328 ? S 0:00 /bin/bash -c /usr/bin/python /opt/ros/hydro/bin/roslaunch gki_3dnav_benchmark nonenav_stack.launch 2>&1 > navstackoutput.txt
24329 ? Sl 0:00 /usr/bin/python /opt/ros/hydro/bin/roslaunch gki_3dnav_benchmark nonenav_stack.launch
It seems to me the node starts but another gets started too, which actually handle the requests. Does anyone know how to prevent this? Or do I do something wrong in my execl
call?
PS: I know it's kind of hacky but still the behaviour confuses me. You can find the benchmark project here. As for why I'm doing it this way is that the sbpl outputs some information to stdout that I want to dump in my evaluation database which are not getting published.
Update: Seems the output gets cutoff too when trying the same thing from the shell
roslaunch gki_3dnav_benchmark nonenav_stack.launch > test.txt
The result of the txt where you can see the cutoff:
[0m[ INFO] [1441555720.539266930, 9773.525000000]: Tolerance rot: 0.200000[0m [0m[ INFO] [1441555720.539284357, 9773.525000000]: Tolerance time: 0.500000[0m [0m[ INFO] [1441555721.024403188, 9773.861000000]: pluginlib WARNING: In file /tmp/buildd/ros-hydro-clear-costmap-recovery-1.11.16-0precise-20150501-0923/src/clear_costmap_recovery.cpp PLUGINLIB_DECLARE_CLASS is deprecated, please use PLUGINLIB_EXPORT_CLASS instead. You can run the script 'plugin_macro_update' provided with pluginlib in your package source folder to automatically and recursively update legacy macros. Base = base_class_type, Derived = derived_class_type[0m [0m[ INFO] [1441555721.025830108, 9
stdout usually buffers a bunch of data when writing to a file; try checking the output file again after your node has exited and actually written all of its output to disk.
Would be odd if that's the reason, when executing "sudo find / > test.txt" I got my results in seconds without a hitch. Btw it's a navstack that runs "indefinitely". I do fork the call and the new pipe doesn receive any new data too.
A tool like find terminates, and flushes the output buffer when it exits; hence a complete file in that case. Since the navstack doesn't exit and isn't constantly writing, it never fills up the log output buffer, and never needs to flush it to disk.
I moved on not parsing the output anymore. I deleted the results where you could have seen, that after the cutoff, the killing notification of the node got written. As far as my understanding goes, redirecting stdout to file should always flush the current output, at least when the process exits.