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

Logging: Add customizable backends #3568

Merged
merged 1 commit into from Apr 27, 2018

Conversation

Projects
None yet
5 participants
@daniellimws
Contributor

daniellimws commented Mar 24, 2018

This is part 2 of #3449 , also a follow-up of #3533

The main goal of this is to change the logging backend to support multiple sinks (console, color console, file, etc) through the Backend interface, with the following changes:

  • Separate logging into its own thread
  • Add support for adding and removing backends on runtime
  • Change logging filter on runtime
  • Button to open log location

As a side effect, on Windows, Citra has to be compiled as a GUI application to make the console hidden by default.

The current way of dealing with large log files is to set a limit of 50MB for logging to file. This should work fine when the log level is not Debug.

On Discord, we discussed about truncating repeated logs. For the aim of reducing the number of lines (spam on console, and also the number of bytes written to file) while still showing there is something being logged, we can print dots and when the message is finally changed show the number of times it was repeated.

One example of a message being repeated 5 times would give something like (of course a better format is needed)

[  51.578907] Audio <Debug> audio_core/time_stretch.cpp:Process:58: Dropping frames!
.... (4)

Currently this has not been implemented yet, still listening to ideas as this will hide potentially important information like time.


This change is Reviewable

@cluezbot

This comment has been minimized.

cluezbot commented Mar 24, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-03-24T12:32:27Z: 327ad8b...daniellimws:2830a409ea51d33ad0cc77f3de20894a2fd46b58

@cluezbot

This comment has been minimized.

cluezbot commented Mar 24, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-03-24T12:57:49Z: 327ad8b...daniellimws:425c79ca6dc7e9ee7046053c82565aed5e592ec8

@jroweboy

This comment has been minimized.

Member

jroweboy commented Mar 24, 2018

https://github.com/citra-emu/citra/pull/3449/files#diff-4eaa9529af469fd20b11df19d2739172R146 <- gcc expects the -mwindows linker flag not the subsystem flag you are passing in there

@daniellimws

This comment has been minimized.

Contributor

daniellimws commented Mar 25, 2018

Oh weird I think that change got lost in one of the rebases.

@cluezbot

This comment has been minimized.

cluezbot commented Mar 25, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-03-25T03:40:44Z: 327ad8b...daniellimws:6050ecf6eed505ac83cf41357b20a6d8ec024afb

backends.push_back(std::move(backend));
}
void RemoveBackend(const std::string& backend_name) {

This comment has been minimized.

@jroweboy

jroweboy Mar 27, 2018

Member

We should prevent issues when removing a backend thats currently writing by locking a mutex in the write_logs and acquiring this lock before removing or adding a backend.

This comment has been minimized.

@daniellimws

daniellimws Mar 27, 2018

Contributor

Yup alright I'll add that.

@daniellimws

This comment has been minimized.

Contributor

daniellimws commented Mar 27, 2018

Are we currently looking into logging to multiple files? If so the name of the FileBackend has to be dependent on the file name, to avoid removing all FileBackends at once with the current implementation.

@jroweboy

This comment has been minimized.

Member

jroweboy commented Mar 27, 2018

@daniellimws I personally think its added complexity that we don't even know if we'll need yet. In my opinion, if we later decide that we need it we can add it, but theres no reason to require it for this part.

@daniellimws

This comment has been minimized.

Contributor

daniellimws commented Mar 27, 2018

Yea that was what I thought. That's good then.

@cluezbot

This comment has been minimized.

cluezbot commented Mar 27, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-03-27T15:56:38Z: 327ad8b...daniellimws:63cf2bff8a30e09e24f0a673265b55a4c30c3a4f

@cluezbot

This comment has been minimized.

cluezbot commented Mar 27, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-03-27T16:23:47Z: 327ad8b...daniellimws:c227514e9e309ac527b10a9197cf211f1b81f332

@cluezbot

This comment has been minimized.

cluezbot commented Mar 27, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-03-27T16:40:16Z: 7446538...daniellimws:cfd30bda25b7e538b08e6c5400f44cec09335cde

@daniellimws daniellimws force-pushed the daniellimws:logging-backends branch from c227514 to cfd30bd Mar 27, 2018

@jroweboy

This comment has been minimized.

Member

jroweboy commented Apr 5, 2018

Will be merging this on the 7th if no one else reviews or merges it by then. It was already thoroughly reviewed when I PRed it, so it should still be ready to go 👍

@jroweboy jroweboy removed the canary-merge label Apr 5, 2018

@FearlessTobi

This comment has been minimized.

Contributor

FearlessTobi commented Apr 5, 2018

@daniellimws Will you implement the log truncation for spammed lines in a follow-up PR?

@daniellimws

This comment has been minimized.

Contributor

daniellimws commented Apr 5, 2018

Would like to listen to more opinions first, as there may be some things to consider, like

  • What if the same log is printed a long time later, do we still truncate? Would the time information be important?
  • What if the same 2 messages are printed continuously, do we care?
#ifdef _WIN32
if (UISettings::values.show_console) {
if (AllocConsole()) {
freopen_s((FILE**)stdin, "CONIN$", "r", stdin);

This comment has been minimized.

@wwylele

wwylele Apr 5, 2018

Member

Are you sure this shouldn't be freopen_s(&stdin, "CONIN$", "r", stdin);?
and if yours is correct, please write it as
freopen_s(reinterpret_cast<FILE**>(stdin), "CONIN$", "r", stdin);
as this is a strange pointer type casting.

This comment has been minimized.

@daniellimws

daniellimws Apr 11, 2018

Contributor

@jroweboy What about this?

This comment has been minimized.

@jroweboy

jroweboy Apr 11, 2018

Member

thats from a stackoverflow comment ^^; i'm not sure either what it should be

@@ -156,7 +156,7 @@ void SplitFilename83(const std::string& filename, std::array<char, 9>& short_nam
class IOFile : public NonCopyable {
public:
IOFile();
IOFile(const std::string& filename, const char openmode[]);
IOFile(const std::string& filename, const char openmode[], int flags = 0);

This comment has been minimized.

@wwylele

wwylele Apr 5, 2018

Member

Please document what flag is used for.

This comment has been minimized.

@jroweboy

jroweboy Apr 10, 2018

Member

@daniellimws to help you document this, flags is used for windows specific file open mode flags. This allows the citra to open the logs in shared write mode, so that the file isn't considered "locked" while citra is open and people can open the log file and view it

@@ -124,23 +251,34 @@ Entry CreateEntry(Class log_class, Level log_level, const char* filename, unsign
entry.timestamp = duration_cast<std::chrono::microseconds>(steady_clock::now() - time_origin);
entry.log_class = log_class;
entry.log_level = log_level;
entry.filename = Common::TrimSourcePath(filename);
entry.filename = std::string(Common::TrimSourcePath(filename));

This comment has been minimized.

@wwylele

wwylele Apr 5, 2018

Member

Is this change intentional?

This comment has been minimized.

@daniellimws

daniellimws Apr 22, 2018

Contributor

Not sure why this is there, removing.

entry.function = function;
entry.message = std::move(message);
entry.function = std::string(function);
entry.message = message;

This comment has been minimized.

@wwylele

wwylele Apr 5, 2018

Member

Is these two change intentional?

This comment has been minimized.

@daniellimws

daniellimws Apr 22, 2018

Contributor

Not sure why this is there, removing.

#include <string>
#include <utility>
#include <boost/optional.hpp>

This comment has been minimized.

@wwylele

wwylele Apr 5, 2018

Member

I don't see where this is needed.

This comment has been minimized.

@daniellimws

daniellimws Apr 22, 2018

Contributor

This was probably a mistake.

@wwylele

This comment has been minimized.

Member

wwylele commented Apr 5, 2018

About log file truncation, I'd say it is fine as-is for this PR (50MB limit). We'll see how well it works and change the method in the future if needed.

@cluezbot

This comment has been minimized.

cluezbot commented Apr 14, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-04-14T07:50:40Z: 7446538...daniellimws:afa38b3d52a86a6a97603991ba8d3bc779332d49

@cluezbot

This comment has been minimized.

cluezbot commented Apr 14, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-04-14T07:56:12Z: 7f408ee...daniellimws:a06c5f7d072a5e2d8dfd0ee9ce4c4bb1495d30da

@cluezbot

This comment has been minimized.

cluezbot commented Apr 22, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-04-22T07:23:41Z: 7f408ee...daniellimws:a2fd2df0767197196d245a8ad9a7dc1c6fe723ba

@daniellimws

This comment has been minimized.

Contributor

daniellimws commented Apr 22, 2018

Oh crap there's some rebasing problem. I'll see what I can do.

@jroweboy jroweboy force-pushed the daniellimws:logging-backends branch from a2fd2df to abdbbf5 Apr 24, 2018

@cluezbot

This comment has been minimized.

cluezbot commented Apr 24, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-04-24T03:29:05Z: 7d8b7d9...daniellimws:abdbbf5a925c0fd3492b291e9bef5406f8aeda5f

Logging: Add customizable logging backends and fmtlib based macros
* Change the logging backend to support multiple sinks through the
Backend Interface
* Add a new set of logging macros to use fmtlib instead.
* Qt: Compile as GUI application on windows to make the console hidden by
default. Add filter configuration and a button to open log location.
* SDL: Migrate to the new logging macros

@jroweboy jroweboy force-pushed the daniellimws:logging-backends branch from abdbbf5 to 51398e0 Apr 24, 2018

@cluezbot

This comment has been minimized.

cluezbot commented Apr 24, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-04-24T03:33:17Z: 7d8b7d9...daniellimws:51398e030148f119c9e89640d5ac641702f9d108

@jroweboy

This comment has been minimized.

Member

jroweboy commented Apr 24, 2018

@daniellimws @wwylele addressed the last small nitpicks, and pushed a rebased commit. please merge when you are ready. To answer your question about the stdin stuff, I did some research and updated the code there as well https://github.com/citra-emu/citra/pull/3568/files#diff-b636b0577a7bb569496810ed9d65ce58R21

@cluezbot

This comment has been minimized.

cluezbot commented Apr 24, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-04-24T04:54:19Z: 7d8b7d9...daniellimws:a00cf9212cd1c88d5b28668061efd65bc926b7f3

@daniellimws

This comment has been minimized.

Contributor

daniellimws commented Apr 24, 2018

Hmm I may have made a mistake...

@jroweboy

This comment has been minimized.

Member

jroweboy commented Apr 24, 2018

@daniellimws i force pushed over your remote branch on github (sorry! was trying to help out with rebasing). if you wanted to keep working on it locally, you'd need to fetch the latest from the remote, and then hard reset to the remote. but now that you've pushed more commits, you can't do that. (you can just force push back to the old version if you needed)

@daniellimws daniellimws force-pushed the daniellimws:logging-backends branch from a00cf92 to 7a36107 Apr 24, 2018

@cluezbot

This comment has been minimized.

cluezbot commented Apr 24, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-04-24T05:05:32Z: 7d8b7d9...daniellimws:7a36107dbbd734bb6d16120d0c02aadc06456e20

@daniellimws daniellimws force-pushed the daniellimws:logging-backends branch from 7a36107 to a2fd2df Apr 24, 2018

@cluezbot

This comment has been minimized.

cluezbot commented Apr 24, 2018

Hi, this is neobot, using neobrain's account. I'm keeping an archive of versions of this PR:

2018-04-24T05:06:36Z: 7d8b7d9...daniellimws:a2fd2df0767197196d245a8ad9a7dc1c6fe723ba

@daniellimws

This comment has been minimized.

Contributor

daniellimws commented Apr 24, 2018

@jroweboy No no I made a mistake 😔 could you do a forced push again really sorry

@jroweboy jroweboy force-pushed the daniellimws:logging-backends branch from a2fd2df to 51398e0 Apr 25, 2018

@jroweboy

This comment has been minimized.

Member

jroweboy commented Apr 27, 2018

@wwylele i'm going to merge with the promise that i'll fix issues with it if they pop up

@jroweboy jroweboy merged commit 1b94f25 into citra-emu:master Apr 27, 2018

2 checks passed

continuous-integration/appveyor/pr AppVeyor build succeeded
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment