Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

On non-Windows systems, send logs to syslog & stderr. #340

Closed
wants to merge 2 commits into from

Conversation

mambrus
Copy link
Contributor

@mambrus mambrus commented Nov 4, 2014

OpenBTS and YateBTS fork a transceiver sub-process and redirect stderr and
stdout, which effectively hide any bladerf logs. For debugging time-critical
code, printf debugging (or logging) is simple yet practically essential.

@mambrus
Copy link
Contributor Author

mambrus commented Nov 4, 2014

jynik: Haven't tested this yet. But I think something like this might suite the need?

@mambrus
Copy link
Contributor Author

mambrus commented Nov 5, 2014

¤2 According to request

¤3 Is a suggestion. Consider it and cherry-pick if it's to your liking, but please don't if you don't like it. Note that even though it has it's benefits, it does not aid to readability. It does however provide a mechanism to initialize which is otherwise easily forgotten by the whoever uses a library. For further explanation and alternative ways, see my answer here: http://stackoverflow.com/questions/2053029/how-exactly-does-attribute-constructor-work

@semcmambrus semcmambrus force-pushed the log2syslog branch 2 times, most recently from 653d806 to 6430e91 Compare November 6, 2014 11:52
@mambrus
Copy link
Contributor Author

mambrus commented Nov 6, 2014

Drawbacks improved. Should at be testable on any platform without braking either build or behavior. Note: pushed with '-f' due to rebase, squashes and amend. Pulls will not merge clean. Throw away old branches and start over (i.e. git fetch, git checkout e.t.a.)

@mambrus
Copy link
Contributor Author

mambrus commented Nov 6, 2014

I mean of course s/improved/eliminated/ , s/at/at least/ and s/braking/breaking/

@jynik
Copy link
Contributor

jynik commented Dec 1, 2014

Quickly test drove this on Linux and OSX -- seems to work well! I still have to just double check for any Windows-related build issues.

Did you have any particular qualms or concerns with the init/fini items? I don't think there's much of a readability issue. Did you have functional or portability concerns? Otherwise, it seems fine to me.

I think the only feedback I have for now is that the "Log verbosity has been set to" and "BladeRF host software (de)initializing" messages at the INFO level create a lot of noise. I'd prefer that these be moved to the DEBUG or VERBOSE levels.

To move forward with pulling this in...

  • I would like to squash these to a single commit that introduces this functionality. I realize that you had them separated for ease of review and can take care of squashing it.
  • Could you send a signed ICAA to bladeRF@nuand.com, or email that address with any questions/concerns on that.

@mambrus,

@jynik jynik self-assigned this Dec 1, 2014
@jynik jynik added the Issue: Enhancement Missing functionality, or a new feature request label Dec 1, 2014
@jynik jynik added this to the 2014.12-rc1 milestone Dec 1, 2014
@mambrus
Copy link
Contributor Author

mambrus commented Dec 8, 2014

Sorry for the late response.

Regarding further functional concerns, I assume what is meant not the the
logging part but the init/fini mechanism.

I'm always concerned by portability. I have no Windows machine to try on,
but apparently there exist a similar mechanism. Will look it up an post a
link here...

My thoughts where furthermore as follows:

  • Having these functions are mainly good for covering situations where
    things need initialization/deinitialization, by SW but where doing so
    risks being forgotten. I beleive however it should be encouraged to do
    initialization/deinotialozation explicitly (i.e. by corresponding public
    peers). To avoid doing the same work twice (double free e.t.a),
    pthread_once can be used and calls be FW to these functions. Encouraging
    this explicit "habit" will cover possible future portability issues and
    improve readability These functions can be hard to find by the novel user
    and therefore easily overlooked (which is a bad thing if funtions in turn
    do more complicated stuff and/or call other functions).
  • Initi/fini additionally is good a place for SW to put self-induced
    breakpoints when debugging processes where code is used as a library
    (either shared or static both works equally well) and where putting such BP
    in main() for one ore another reason isn't feasable. I have deployed this
    technique with good results debugging YateBTS transceiver in the
    OpenBTS/YateBTS hybrid.
  • For Windows neither of the above is a critical issue as currently the
    only initi is initializing syslog, which Windows lack.
  • One possible corner-case where explicit calls and this mechanism will
    differ is explicit library load and unload. Especially if HW states can be
    affected. Pthread_once can again be used, but then the control variable
    needs to be extern. It's an unlikely case and I don't think special care
    needs to be taken. Mentioned for the record though.

Will fix squash, log-level and icaa ASAP.

Regards

Quickly test drove this on Linux and OSX -- seems to work well! I still
have to just double check for any Windows-related build issues.

Did you have any particular qualms or concerns with the init/fini items? I
don't think there's much of a readability issue. Did you have functional or
portability concerns? Otherwise, it seems fine to me.

I think the only feedback I have for now is that the "Log verbosity has
been set to" and "BladeRF host software (de)initializing" messages at the
INFO level create a lot of noise. I'd prefer that these be moved to the
DEBUG or VERBOSE levels.

To move forward with pulling this in...

@mambrus https://github.com/mambrus,


Reply to this email directly or view it on GitHub
#340 (comment).

@mambrus
Copy link
Contributor Author

mambrus commented Jan 12, 2015

New upload according to comments.

NOTE: This is a forced push.

Original pre-squashed commits (complete branch) is moved here for future reference: https://github.com/mambrus/bladeRF/tree/log2syslog_NOT_squashed

OpenBTS and YateBTS fork a transceiver sub-process and redirect stderr and
stdout, which effectively hide any bladerf logs. For debugging time-critical
code, printf debugging (or logging) is simple yet practically essential.
Logging to syslog made opt-in. To enable:

-DDENABLE_LIBBLADERF_SYSLOG

To make this as transparent as possible, a generic mechanism for
initializing libraries without having to use any specific pre-known function
has been introduced (see init_fini.c). Currently it's only real purpose is
to closelog() upon unloading library. Failing doing this is an error
affecting the case library is unloaded manually.
Commit covers two cases:
1) bladerf-CLI type of case where bladerf_log_set_verbosity is set by the
   application, one doesn't want unexpected verbosity during app-startup.

2) Spawned processes that use bladerf as a library. These need a fair
   default, but also require verbosity to be adjustable without requiring
   additional interfaces.

To cover both these, fall-back default is to have verbosity set to
BLADERF_LOG_LEVEL_WARNING. However, libbladerf will listen to the
environment variable BLADERF_LOG_LEVEL. If set, it's value will be used as
library default instead.
@jynik
Copy link
Contributor

jynik commented Jan 13, 2015

I pulled this into the Nuand repo in a dev-issue_345 branch with a couple minor changes.

As you'll see, I'd prefer the use of str2loglevel() over atoi(), allowing the use of BLADERF_LOG_LEVEL=debug or BLADERF_LOG_LEVEL=verbose rather than numbers that I personally could never remember.

@jynik
Copy link
Contributor

jynik commented Jan 14, 2015

Tested on OSX. Just a heads up, it looks like each log_*() call causes a broadcast message to be sent to every TTY. This is just with a bladeRF-cli -i -v verbose, without using the log-level env var.

Do you have any OSX boxes to take a gander at this?

@jynik
Copy link
Contributor

jynik commented Jan 14, 2015

Looks like the above behavior is the result of a system config for emergency messages, based on my /etc/asl.conf, shown below. Perhaps we're not specifying the correct syslog level for OSX?

##
# configuration file for syslogd and aslmanager
##

# authpriv messages are root/admin readable
? [= Facility authpriv] access 0 80

# remoteauth critical, alert, and emergency messages are root/admin readable
? [= Facility remoteauth] [<= Level critical] access 0 80

# broadcast emergency messages
? [= Level emergency] broadcast

# save kernel [PID 0] and launchd [PID 1] messages
? [<= PID 1] store

# ignore "internal" facility
? [= Facility internal] ignore

# save everything from emergency to notice
? [<= Level notice] store

# Rules for /var/log/system.log 
> system.log mode=0640 format=bsd rotate=seq compress file_max=5M all_max=50M
? [= Sender kernel] file system.log
? [<= Level notice] file system.log
? [= Facility auth] [<= Level info] file system.log
? [= Facility authpriv] [<= Level info] file system.log

# Facility com.apple.alf.logging gets saved in appfirewall.log
? [= Facility com.apple.alf.logging] file appfirewall.log file_max=5M all_max=50M

@jynik
Copy link
Contributor

jynik commented Jan 14, 2015

Integrated in 344d497

@jynik jynik closed this Jan 14, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Issue: Enhancement Missing functionality, or a new feature request
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants