Bitshares-core: Log file of current hour gets overwritten by default

[abitmore]

Steps to reproduce:

• change config.ini so default log will be written to file

# declare an appender named "default" that writes messages to default.log
[log.file_appender.default]
filename=logs/default/default.log
# filename can be absolute or relative to this config file

# route any messages logged to the default logger to the "stderr" logger and "default" logger we
# declared above, if they are info level are higher
[logger.default]
level=info
appenders=stderr,default

• start witness_node
• stop witness_node
• check log file (witness_node_data_dir/logs/default/default.log)
• start witness_node again
• check log file (witness_node_data_dir/logs/default/default.log)

The log file will be overwritten on restart.

IMHO the default behavior should be appending but not overwriting.

CORE TEAM TASK LIST

• [x] Evaluate / Prioritize Feature Request
• [x] Refine User Stories / Requirements
• [ ] Define Test Cases
• [ ] Design / Develop Solution
  
  
  
  • [x] Issue estimation: 2 hours
  
  
  • [x] Issue assigned to @nanomobile
  
  
• [ ] Perform QA/Testing
• [ ] Update Documentation

[clockworkgr]

Not completely confident in C++ coding yet to simply do a PR, but since I wanna start getting involved, I just wanna run this by you.

It seems that here:
https://github.com/bitshares/bitshares-fc/blob/master/src/log/file_appender.cpp#L148

The file is opened , passing a bitmask for write & append mode.

However, here:
https://github.com/bitshares/bitshares-fc/blob/master/src/io/fstream.cpp#L32

It seems like the bitmask passed is ignored and opening in binary mode is hardcoded in instead.

I assume the correct way of tackling this is to fix fstream.cpp to use the bitmask passed and visit all calls to open() to make sure that binary mode is added to the bitmask.

Am I correct in any of this?

[nanomobile]

I want to claim this issue, help me guys please to make correct workflow for first time

[ryanRfox]

@nanomobile has claimed this Issue. I've moved it to the Community Claims project board. The OP provides hints for a Test Case. Also, @clockworkgr provides hints above for potential fixes within fstream.cpp and confirmed by @abitmore . Please begin your local development with a checkout from the develop branch. Please rebase your local feature branch prior to creating your PR to develop.

[nanomobile]

how much hours is reserved for this issue ?

[nanomobile]

What is your estimates on this issue so the Community know how many hours it is expected to take ?

[ryanRfox]

@nanomobile Checking with Core Team devs for assistance with estimation...

[nanomobile]

Thanks a lot !
Have a perfect day !

[oxarbitrage]

i am not very good in estimations but i will say it will take 1 hour to someone with the needed knowledge of git and bitshares. clockwork already pointed to some code where it can be fixed. it could take some more(2 hours) to someone not that familiar with any of this but i think not much more than that in this particular case.

the estimations in general i think can be done with a floor of no less than 1 hour and a variable roof in case something is more complicated than initially estimated or reviewers request changes to the code, etc)

[nanomobile]

while debugging I found that problem isn't located as clockwork wrote.

[clockworkgr]

Yeah, don't take my comment as gospel...my c++ knowledge is rudimentary at best...I just wanted to know if I was thinking across the right lines

[nanomobile]

yes sure ! Understood ! I thought the same as you ;-) Just checked your version :-) I thought you're right and I can fix it less than 1 hour :-) but need to research & debug more ...

[oxarbitrage]

can be extended to 2 hours without problems IMO.

[jmjatlanta]

I'd say 1 1/2 to 2hr is fair.

* Warning... Soapbox *
While some may balk at the time it takes to handle a task, please remember that often this must include research, estimation, consultation, implementation, testing, and documentation.

I'm not saying this task requires all these steps. But coding time is only part of the equation. Often, we attack a problem only to find that it affects something else. Or find that if we do it the right way, we also have to adjust this "other thing over there".

My $0.02 (includes the $0.02 VAT), is that the potential candidate should have a clear understanding of what is expected, and can assist in the estimation. The first few attempts are a learning experience, and often cost the developer. But the rewards are there for endurance (speaking from experience on this point).

If tasks grow beyond the initial requirements (this happens more often than we want), we should reward the developer for the value of what they were able to accomplish, even if the results are only documentation of a deeper problem.
* stepping down from soapbox *

[ryanRfox]

@nanomobile Let's call it estimated at 2 hours. I know you already have some time into. Thanks much!

@oxarbitrage @jmjatlanta Thanks for helping me with this estimation. I really appreciate your words above @jmjatlanta as they accurately reflect my feelings as well.

[ryanRfox]

A note to Core Team: I added the __Core Team Task List__ section to the description (this is part of our New Issue template, so need to add it into legacy Issues manually). For the Community Claims Issues like this one we can add tasks for _assignee_ and _estimation_ to help us quickly coordinate.

Note that the __UI Team__ adds a bracketed numeric value prefix once estimated, i.e. [2] Issue Title. Comments on how we want to do this are appreciated.

[nanomobile]

1 hour or 2 hours not a problem :-) But really how many hours it will take I will know later when this issue will be finished ;-) I'm still debugging code and research fully BitShares C++ code, because it's not very well known by me yet ...

[nanomobile]

Thanks a lot guys for your help and patience ! 👍

[nanomobile]

@clockworkgr you're absolutely right about issue location ! After debugging more and more BitShares C++ code, I've found in another thread that after executing this line of code https://github.com/bitshares/bitshares-fc/blob/master/src/io/fstream.cpp#L32 at some point in time we can see the problem. For me it took too long because I've installed environment from scratch specifically to develop BitShares C++ code, also I'm still research the whole C++ project, want to know every detail. Also synchronization took a lot of time. Just for development puproses how is it possible to run full node from scratch with empty history and without connecting to main net, just something like private net ? Are in the web any instructions about running full node locally on private/custom net ?
Now debugging code to understand how to fix the issue correctly. @oxarbitrage @jmjatlanta @ryanRfox I agree with you absolutely ! First time is always harder than next times, that's why I need to learn much more better the whole BitShares C++ project to fix issues much faster with the best quality !
Thanks guys ! Soon will make PR. Just give me please a bit more time to research the whole project better and better :-)

[nanomobile]

there is a mystic :-) cannot understand if the problem really located here https://github.com/bitshares/bitshares-fc/blob/master/src/io/fstream.cpp#L32 or not here :-)
I've changed that line of code to next one (just for test purposes only) my->ofs.open( bfp, std::ios::app | std::ios::out | std::ios::binary ); and while debugging - new data was appended, but after some time I saw again that the new data wasn't appended but replaced old data. Very strange behavior I see, still need to make more researches and to debug more and more the code. That's why 1st time I thought that @clockworkgr wrote wrong the line of code where the issue is located and 2nd time I thought he is absolutely right with line of code where is the issue located. Now in 3rd time cannot understand but seems that the issue isn't located here https://github.com/bitshares/bitshares-fc/blob/master/src/io/fstream.cpp#L32 and isn't located here too https://github.com/bitshares/bitshares-fc/blob/master/src/io/fstream.cpp#L64. Trying to understand every detail while debugging ... Guys thank you for your patience, help and efforts ! Give me please time to research and debug code more deeply in order to fix this issue and future issues correctly and fastly :-)

[nanomobile]

PS: maybe you misunderstood my message about more time - I didn't mean more payed time :-) just more time for me to research better the whole project

[nanomobile]

after debugging and researching the whole project better and better I found that problem is located here
https://github.com/bitshares/bitshares-core/blob/master/libraries/app/application.cpp#L121

this line of code deletes all content inside default.log file and after that new logs are added in this default.log file, that's why even if we make append in fstream.cpp code we will lose all old content inside default.log file.

[abitmore]

@nanomobile still need to find how to fix. I believe we can't remove that line of code.

[nanomobile]

yes sure we cannot delete it, we need just to fix it, still researching and debugging the code.

[nanomobile]

@ryanRfox @jmjatlanta @oxarbitrage @abitmore @clockworkgr, does the estimation of time for this issue remain the same ?

Maybe we need to open another issue/feature because here we need to change a lot of code IMHO to fix this issue. Still researching more and more the code and debugging it again and again.

[abitmore]

@nanomobile depends on your final solution. Show us the details, E.G. why need to change a lot of code, is it the best approach, and etc.

[jmjatlanta]

I'm jumping in without following the details of the story, so sorry if my comments seem out of place.

RE: The line of code at https://github.com/bitshares/bitshares-core/blob/master/libraries/app/application.cpp#L121

What about that line of code causes the log file to be erased? I fail to see it.

A "simple" task often leads to more work than initially thought. So adjustments to estimates are common. But please explain the "why" and we'll take a look.

[nanomobile]

I'm still researching the code more and more, but as I see now I need to save old logs before default.log file will be deleted and after that I need to paste old logs before new logs will be added and of course I need to make it correctly. Maybe I'm wrong with my solution that's why I'm still debugging and researching the whole code.

[nanomobile]

also when any task is finished it really seems simple ! :-)

[nanomobile]

@ryanRfox @jmjatlanta @abitmore @clockworkgr @oxarbitrage
After deeper researches and debugging I've found the real problem is located here (really simple seems now) :

https://github.com/bitshares/bitshares-fc/blob/0d689a4894957a24fedac7ae302be0268f19cbe1/src/log/file_appender.cpp#L85

Soon will fix it correctly (we cannot just comment or remove that line of code) and will make PR

Also I see next strange snippet of code in file_appender.cpp

https://github.com/bitshares/bitshares-fc/blob/0d689a4894957a24fedac7ae302be0268f19cbe1/src/log/file_appender.cpp#L86-L89

if( fc::exists( log_filename ) )
                  out.open( log_filename, std::ios_base::out | std::ios_base::app );
               else
                  out.open( log_filename, std::ios_base::out | std::ios_base::app);

There are the same 2 lines of code, why ?

[oxarbitrage]

probably something left by old code, can replace the 4 lines into just out.open( log_filename, std::ios_base::out | std::ios_base::app ); in your pull request. please make sure you send it to develop branch. thanks.

[nanomobile]

we need not only 1 line, we need 2 lines of code:

fc::exists( log_filename ); // creates file if not exists
out.open( log_filename, std::ios_base::out | std::ios_base::app );

yes sure pull request will send to develop branch only

[oxarbitrage]

fc::exists( log_filename ); returns bool so the first line of your snippet do nothing, only valid if inside an if, assert or something.

[nanomobile]

@oxarbitrage

fc::exists( log_filename ); - creates file if it not exists, I've tested it, or am I wrong ? :-)

a bit later I will test it again ...

[nanomobile]

@oxarbitrage you're absolutely right about fc::exists( log_filename ) - doesn't create file implicitly as I've thought, just was a bit missunderstood, because I've made a lot of researches, a lot of tries, a lot of experiments :-) sorry if I've confused you ...

@abitmore @clockworkgr @jmjatlanta @ryanRfox @oxarbitrage

Pull Request is ready here
https://github.com/bitshares/bitshares-fc/pull/56
https://github.com/bitshares/bitshares-core/pull/1102

PS: this issue was really easy, but not for 1st time :-) because 1st time always requires more time and more efforts for researches

[abitmore]

@nanomobile Thank you. I've commented in the PR.

[nanomobile]

@abitmore :+1: Thanks !

[nanomobile]

now everything most work as required without having huge log files, I've fixed default behaviour and checked it also

[abitmore]

The situation:

• currently fc::ofstream effectively supports only "binary + overwrite" mode
• there is a mode parameter but not used
  
  
  
  • default value is a self-defined value mode::binary, which is not compatible to std::ios_base::binary: https://github.com/bitshares/bitshares-fc/blob/c16bb206a39b09b03423088c831bc193de89056c/include/fc/io/fstream.hpp#L10-L15
  
  
• some code is using "binary + overwrite" mode, by not setting the 2nd parameter: https://github.com/bitshares/bitshares-core/blob/af118f697319d473b2547e2b110d0493980ac2b4/libraries/egenesis/embed_genesis.cpp#L283-L285
• some code tried to use the 2nd parameter to "append" mode but failed (https://github.com/bitshares/bitshares-core/issues/809),
  
  
  
  • don't know if "binary" mode is desired in this case
  
  
• there may be code elsewhere using it and perhaps expecting other behaviors.

What we want:

• able to use append mode

Things to discuss:

• do we want to support non-binary mode, aka "text" mode?
  
  
  
  • if yes, what's better to be the default behavior? IIRC "text" mode is the default mode in STD library, it may be confusing if our library have different default behavior;
  
  
  • if not, we should document it somewhere, probably better rename the class to binary_ofstream or so.
  
  

Suggestions so far (if to not support text mode):

• change the type of the 2nd parameter to std::ios_base::openmode mode, and
  
  
  
  • change the default value to std::ios_base::out | std::ios_base::binary
  
  
  • if the 2nd parameter is set, open the file with std::ios_base::out | std::ios_base::binary | the_given_value
  
  

[nanomobile]

the same situation touches fc::ifstream as I can see

[jmjatlanta]

My suggestion would be to make fc's mode enum values match std::ios_base flags to fix this issue, and perhaps open another issue to refactor fc::fstream.

@nanomobile please don't use my suggestion unless @abitmore or others agree that is the best option.

[abitmore]

@jmjatlanta std::ios_base::openmode is not enum but bit flags or bit masks.

@nanomobile ifstream has only the binary issue, but don't have the "append mode" issue. See this link for more info: https://en.cppreference.com/w/cpp/io/ios_base/openmode

[jmjatlanta]

std::ios_base::openmode is not enum but bit flags or bit masks.

I was thinking we could map it to match the std::ios_base values. We wouldn't want to hard-code it to platform specific values, but here is a piece from ios_base.h on my machine (Ubuntu 16.04):

enum _Ios_Openmode 
{ 
   _S_app       = 1L << 0,
   _S_ate       = 1L << 1,
   _S_bin       = 1L << 2,
   _S_in        = 1L << 3,
   _S_out       = 1L << 4,
   _S_trunc         = 1L << 5,
   _S_ios_openmode_end = 1L << 16,
   _S_ios_openmode_max = __INT_MAX__,
   _S_ios_openmode_min = ~__INT_MAX__
};

and

    typedef _Ios_Openmode openmode;

    /// Seek to end before each write.
    static const openmode app =     _S_app;

    /// Open and seek to end immediately after opening.
    static const openmode ate =     _S_ate;

    /// Perform input and output in binary mode (as opposed to text mode).
    /// This is probably not what you think it is; see
    /// https://gcc.gnu.org/onlinedocs/libstdc++/manual/fstreams.html#std.io.filestreams.binary
    static const openmode binary =  _S_bin;

    /// Open for input.  Default for @c ifstream and fstream.
    static const openmode in =      _S_in;

    /// Open for output.  Default for @c ofstream and fstream.
    static const openmode out =     _S_out;

    /// Open for input.  Default for @c ofstream.
    static const openmode trunc =   _S_trunc;

[nanomobile]

guys what do you think about @jmjatlanta 's idea ? Do you see any other much better solutions ?

[nanomobile]

I'm still researching the code and thinking about @jmjatlanta 's idea ... this solution seems good enough, but need to think a bit more :-)

[abitmore]

I've mentioned my opinions above, quoting here:

• change the type of the 2nd parameter to std::ios_base::openmode mode, and
  
  
  
  • change the default value to std::ios_base::out | std::ios_base::binary
  
  
  • if the 2nd parameter is set, open the file with std::ios_base::out | std::ios_base::binary | the_given_value
  
  

[jmjatlanta]

I'd say @abitmore has a good solution. That would require the minimal amount of changes to source code and fix the current problem. I think a separate issue should be created to refactor fc::fstream so as to be consistent with standard fstream expectations (i.e. text mode). I will create that issue.

[nanomobile]

so @abitmore 's solution is the best ? right ? Should I implement it ? does anybody disagree ?

[nanomobile]

@abitmore yes I mean ifstream has binary issue, the same situation means that there is issue too with ifstream :-)

[nanomobile]

new changes in PR are ready
https://github.com/bitshares/bitshares-fc/pull/56

https://github.com/bitshares/bitshares-fc/pull/56/commits/71b6f154a62491c91a9dcdc29e9333e32f97f8d0

@abitmore @oxarbitrage @jmjatlanta @ryanRfox @clockworkgr so we can close this issue and merge changes from this PR ?

[abitmore]

Fixed with #1104.