Logger not working in recursive function calls.

[AhmedSamara]

@dfarrell07

Inside of follower.py on branch pilot_dev, I have a function recover() that recursively calls itself until the robot is back in a reasonable position.

Unfortunately, the logger doesn't seem to work in any of the lower layer calls.

[dfarrell07]

ACK, looking at this now.

[dfarrell07]

What's the best way for me to reproduce this?

[AhmedSamara]

I don't suppose you happen to own your own beaglebone?

[dfarrell07]

lol, no I don't (if I did I would have donated it to you all).

tl;dr is that I'm not sure what's going on and I'm trying to get CtrlServer running in the Vagrant environment (so via ./start -Tsc) and/or the tests passing so I can debug running code.

Dumping an initial response that I know is off-base now (after debugging through it and logging process in Markdown as a comment).

Notes/dump thing: https://gist.github.com/dfarrell07/4abfa3f910345ea1fabb

[dfarrell07]

Initial thoughts about the lack of logging output

• Are you sure the lower layer calls are being made?
• I doubt it's an issue with the Logger object itself.
• There aren't any additional, unexpected log files being created are there?
• Are you looking in the file or just stdout/stderr?

This is really hard to debug without running code.

[AhmedSamara]

I was using tail -f bot.log | grep recover to view the live output and nothing showed up, and afterwards I checked the file manually.

I'm just calling self.logger.debug(msg) and it's not showing up at all. I tried grepping through the file and don't find anything else being logged from "follower" besides the top level call.

[dfarrell07]

I tried grepping through the file and don't find anything else being logged from "follower" besides the top level call.

That's interesting, digging...

[dfarrell07]

Can you provide the log file via gist/pastebin/whatever?

[AhmedSamara]

So I might be a little bit crazy now, but it seems to be working again... I have no idea how/why I managed to trick myself into thinking it wasn't, I guess it just wasn't reaching the lower-level calls. Sorry about that Daniel.

[dfarrell07]

Update on getting CtrlServer running off a bone.

Manually (well, with Vim) setting all of the component-specific testing flags in config.yaml to true results in the following failure when starting a CtrlServer in test mode with recent code from the pilot_dev branch.

vagrant@packer-debian-7:~/bot/bot$ ./start.py -Tsc
Using simulated hardware
Starting server
ctrl_server.py | __init__ | 91 | INFO | CtrlServer running in test mode
ir_hub.py | __init__ | 64 | ERROR | Unable to create front IR array
ir_hub.py | __init__ | 64 | ERROR | Unable to create right IR array
ir_hub.py | __init__ | 64 | ERROR | Unable to create back IR array
ir_hub.py | __init__ | 64 | ERROR | Unable to create left IR array
color_sensor.py | get_baseline | 195 | ERROR | Baseline found on 1 attempt.
Could not open I2C bus 1: [Errno 2] No such file or directory
WARNING: address 0x00 not valid for config!
Traceback (most recent call last):
  File "./bot/server/ctrl_server.py", line 324, in <module>
    server = CtrlServer(sys.argv[1])
  File "./bot/server/ctrl_server.py", line 116, in __init__
    self.systems = self.assign_subsystems()
  File "./bot/server/ctrl_server.py", line 137, in assign_subsystems
    self.rubiks_solver = rubiks_mod.RubiksSolver()
  File "/home/vagrant/bot/bot/activity_solver/rubiks_solver.py", line 41, in __init__
    self.pwr.output()
  File "/home/vagrant/src/bbb/bbb/gpio.py", line 38, in output
    with open(self.direction_path, 'w') as f:
IOError: [Errno 2] No such file or directory: '/sys/class/gpio/gpio88/direction'

Which is a pretty manageable looking error.

Looking at in bot/activity_solver/rubiks_solver.py (via the stack trace), note that we're skipping the motor.py hardware abstraction layer and working directly with hardware.

        # gpio's that control motors of gripper.
        # Note: we're not using motor.py, it assumes strange hardware.
        # TODO(AhmedSamara): update motor.py to update standard hardware.
        self.rev = gpio_mod.GPIO(self.rev_num)
        self.fwd = gpio_mod.GPIO(self.fwd_num)
        self.pwr = gpio_mod.GPIO(self.pwr_num)

So we're not making the testing/not-testing check that's normally handled by the the motor hardware abstraction.

        if config["test_mode"]["motor"]:
            # Get dir of simulated hardware files from config
            pwm_test_dir = config["test_pwm_base_dir"]

            # Build PWM object for BBB interaction, provide test dir
            self.pwm = pwm_mod.PWM(self.pwm_num, pwm_test_dir)

            if self.gpio_num is not None:
                # Build GPIO object for BBB interaction, provide test dir
                gpio_test_dir = config["test_gpio_base_dir"]
                self.gpio = gpio_mod.GPIO(self.gpio_num, gpio_test_dir)
        else:
            # Build PWM object for BBB interaction
            self.pwm = pwm_mod.PWM(self.pwm_num)

            if self.gpio_num is not None:
                # Build GPIO object for BBB interaction
                self.gpio = gpio_mod.GPIO(self.gpio_num)

So RubiksSolver is ignoring test mode, trying to write to real GPIOs and failing when it's not on a bone.

So, short of fixing that TODO and moving back to the motor abstraction, I don't see a good-ish way to run CtrlServer (so the Follower code) on simulated hardware.

If I were to fix the other (unrelated to this) errors I'm getting from tox -epy27, I would run into this eventually (still don't have a bone).

[dfarrell07]

Sorry about that Daniel.

Well, at least I'm refreshed on the code base now, lol. Glad you're un-stuck. :)