97 replies to this topic

[christophecvr]

 

It seems logical not to do any debugging at all if you're not running in debug mode.

 

I for myself introduced in enigma printk level check: https://github.com/T.../eerror.cpp#L83
If I want to receiver work a little faster, and I do not need a log, I cut down prink level and I do not have in log unnecessary spam.

 

This definitely needs to be improved, but maybe you can use something similar.

 

It's a way of thinking but does not really solve the always execution off already inserted eDeug(...) lines. Which if console is actif or not will always be done. And the lock will always be applied and that's the problem, to avoid a data collision due to multiple access of same file,buffer or mem segment at the same fraction of time the lock is required.

 

That's why in first stage :

 

1) First stage very urgent and must have been done yesterday

    Remove all the not needed eDebug by just commenting them why now just commenting . its' very urgent , as for how to thread them in future must be discussed.

 

note: for servicemp3.cpp i issued a patch already which should have been applied yesterday

but i'm shure there are other modules containing such eDebug lines which are blocking stable working, persons working on this should also issue patches to comment asap unneeded eDebug outputs.

 

2) Ok we have time the critical bugs caused due to the over using of eDebug are stopped time to:

 

   - Asses the whole project e2 upon debuging.

   - Check if it was not already foreseen to issue debug messages only if enigma2 has a start parameter for it.

   - Then brainstorm about possible solutions new options and .....

 

3) Well wait on the results off last point in 2

[christophecvr]

@all pli core members developpers ,

 

I fully agree the title of this topic is wrong. Even adding a function like I did initially is even not wrong but totally crazy sorry sorry sorry .

 

But the patch to servicemp3.cpp is very very very URGENT !!!.

 

Also to all who are currently developing some functions or improvements check the use off any debug line used as they are always printed.

 

It would be nice that one off the devs change the title of this topic and eventually pinpoint it since the debug in e2 is a major bug on itself. To just remove , there is no time left to asses and discuss that , for that reason we need first start whit just commenting the ones who are must probably  responsible off sand keeper , temp freeze or full freeze .

 

The worsted scenario we can have is e2 crash followed by restart again e2 start this in a continu scenario. ..... , the regular user may end up with the requirement to reflash the box to solve.

The second one is a full stb freeze the regular user will only be able to do a hard power reset (bad for the stb).

 

Those two above maybe triggered by over debugging which is in the current pli4 the case.

Edited by christophecvr, 13 January 2016 - 17:28.

[betacentauri]

What boxes are affected? All? I only heard that VU+ boxes show spinners? Right? If this is not clear it should be tested.

 

As already said is writing to console without lock not the best idea. E2 uses several threads and if 2 threads want to write a debug message they shouldn't write at the same time, because then you might see mixed/scrambled text in the console.

 

Disabling debug out is not an option for me. If E2 crash you should see debug messages in the crash log. So you need to store them and you need a lock to prevent scrambled text. Some errors only occur in rare cases. You cannot tell the user that he has to start E2 from command line 100 times to create a useful crashlog.

 

Maybe you could store the last message in eDebug. If new message is the same as the last one, don't write it or only write it once every second. But I'm not sure whether this solves the problem. Is there a faster locking mechanism?

[christophecvr]

What boxes are affected? All? I only heard that VU+ boxes show spinners? Right? If this is not clear it should be tested.

 

As already said is writing to console without lock not the best idea. E2 uses several threads and if 2 threads want to write a debug message they shouldn't write at the same time, because then you might see mixed/scrambled text in the console.

 

Disabling debug out is not an option for me. If E2 crash you should see debug messages in the crash log. So you need to store them and you need a lock to prevent scrambled text. Some errors only occur in rare cases. You cannot tell the user that he has to start E2 from command line 100 times to create a useful crashlog.

 

Maybe you could store the last message in eDebug. If new message is the same as the last one, don't write it or only write it once every second. But I'm not sure whether this solves the problem. Is there a faster locking mechanism?

Nice but You just only repeat what I already said at the same time why .

 

Yes I did told that using the eDebugNoLock would cause even more problems then now and may square the problems we already have.

 

The boxes who have problems ?? well one answer "ALL"

 

Just look at the function and use off it. It's pure coincidence that I found the link as from where the sand keeper came. Like I told in a first phase it is very very URGENT to at least comment some eDebugs. For servicemp3.cpp I already issued a patch here, it should have been applied yesterday. But there are much more places in e2 where there is to much use off eDebug or any off the other debug functions. I, in the mean time start to know quit the servicemp3.cpp player .To do the action I did in the patch in other modules must be done by a person who is really busy with the concerned module. However "ASAP"

 

For the rest yes assessment , brainstorm and discussion is needed  . It's clear that a major change about debugging and info is needed . Before any action a real plan must be made .

Edited by christophecvr, 13 January 2016 - 19:18.

[theparasol]

My 2 cents: In case of gstreamer buffermessages, gstreamer sends them far too many. The buffer isnt even increasing in percentage. What use does it have to waste cpu cycles just to let us know there is 1 byte added to the buffer?

Only thing we want to know: buffer is empty, buffer is decreasing, buffer is increasing, buffer is full. That should be implemented (in gstreamer I think, but I didnt look at the code)

decreasing or increasing should only be send if previous status was not decreasing or increasing.

[mirakels]

I don't think eDebug is a bug! IF you put the wrong code at the wrong place you can break everything. For that matter you may argue that a while loop is a bug.

 

 

But the debugging system can be improved.....

About the locking. I guess locking is done at the wrong place. It should be done where it is needed. I think is should be where the ringbuffer is actually filled. I.e in the addToLogbuffer() function.

Next I remember a discussion recently about introducing eDebug log levels that can be set dring runtime by means of environment variables..

Combining these the amount of log can be managed and the number of locks can be reduced.

[mirakels]

My 2 cents: In case of gstreamer buffermessages, gstreamer sends them far too many. The buffer isnt even increasing in percentage. What use does it have to waste cpu cycles just to let us know there is 1 byte added to the buffer?

Only thing we want to know: buffer is empty, buffer is decreasing, buffer is increasing, buffer is full. That should be implemented (in gstreamer I think, but I didnt look at the code)

decreasing or increasing should only be send if previous status was not decreasing or increasing.

Exactly (part) of my point. Think about what you log. For burref percentages you could code something like

 

     if percentage_diff_since_last_log > 5% then issue_log()

[christophecvr]

Well yes but  .... the day if gstreamer stops sending a message about a buffering event whatever it is they will be canonised with complains . No gstreamer does nothing wrong about that. But we in enigma2 are treating it wrong. A buffering msg should never be logged it always will be a tremendous log without any useful value. Unless You really need to trace a issue which could be related to that. That is now the reason why tracing should be added.

 

This means the line 2089 (and only the eDebug line the rest is needed) should never have been set for regular working conditions, with eDebug its always set the problems it cause is actually logic , but it's one off the mean sources why e2 has a sand keeper with a lot off streamed media and yes even with a dm8000, In this particular case the faster the box and cpu the faster you run into troubles even that is logic.

 

But after the discovering of the issue ..... Checking out other ones which are not so heavy weight but pretty irritating such like the use off srt subs (build in) or extrenal srt subs. Could sometimes majorly when You resumed a movie be out off sync not showing or showing after xxxx seconds not very nice. Well by just removing the eDebugs off the subtitles all those problems are gone .

 

So to already solve the major issues it does cause with servicemp3.cpp I did issued a patch and it should have been committed yesterday. And it is still not done ?? why it does very few excepting comment total useless debug outputs .

[mirakels]

Nothing should have been done because you have made something.

One creates something and offers it to be included. Sometimes things can be included directly, sometimes one may discuss this and decide if it is the proper way to do this.

And as eDebug is already been discussed earlier I think it is a good thing to further discuss this topic before blindly patching , repatching, reverting, patching again and finally decide it is the wrong way of doing and sit together and design something new.

 

So please do not give 'orders'. Nobody is emplyed/paid here for the work done at openPli.

 

We have lived with this debug line for a while I guess so a few days extra won't hurt that much, especially if the public feels we're all on the way to improve on this.

 

So lets look forward and not discuss why something was not done yesterday.

[theparasol]

Patience my friend!

It has been in for a very long time, some additional time wont hurt either.

Most important is that we now are aware of the issue.

[christophecvr]

Well I do not give orders but I well showed proved and .. for more then 4 days An extreme BUG in e2 is present.

A lot of guys are still working on issues who are freaky and un explained even not logic.

 

This all just only because eDebug or actuallyy ALL functions in eerror.cpp may cause a problem.

I made the collection off it ,

#ifdef DEBUG
void eDebug(const char* fmt, ...)
{
    char buf[1024];
    struct timespec tp;
    clock_gettime(CLOCK_MONOTONIC, &tp);
    snprintf(buf, 1024, "<%6lu.%06lu> ", tp.tv_sec, tp.tv_nsec/1000);
    va_list ap;
    va_start(ap, fmt);
    vsnprintf(buf + strlen(buf), 1024-strlen(buf), fmt, ap);
    va_end(ap);
    singleLock s(DebugLock);
    logOutput(lvlDebug, std::string(buf) + "\n");
    if (logOutputConsole)
        fprintf(stderr, "%s\n", buf);
}

void eDebugNoNewLineStart(const char* fmt, ...)
{
    char buf[1024];
    struct timespec tp;
    clock_gettime(CLOCK_MONOTONIC, &tp);
    snprintf(buf, 1024, "<%6lu.%06lu> ", tp.tv_sec, tp.tv_nsec/1000);
    va_list ap;
    va_start(ap, fmt);
    vsnprintf(buf + strlen(buf), 1024-strlen(buf), fmt, ap);
    va_end(ap);
    singleLock s(DebugLock);
    logOutput(lvlDebug, std::string(buf));
    if (logOutputConsole)
        fprintf(stderr, "%s", buf);
}

void eDebugNoNewLine(const char* fmt, ...)
{
    char buf[1024];
    va_list ap;
    va_start(ap, fmt);
    vsnprintf(buf, 1024, fmt, ap);
    va_end(ap);
    singleLock s(DebugLock);
    logOutput(lvlDebug, std::string(buf));
    if (logOutputConsole)
        fprintf(stderr, "%s", buf);
}

void eWarning(const char* fmt, ...)
{
    char buf[1024];
    struct timespec tp;
    clock_gettime(CLOCK_MONOTONIC, &tp);
    snprintf(buf, 1024, "<%6lu.%06lu> ", tp.tv_sec, tp.tv_nsec/1000);
    va_list ap;
    va_start(ap, fmt);
    vsnprintf(buf + strlen(buf), 1024-strlen(buf), fmt, ap);
    va_end(ap);
    singleLock s(DebugLock);
    logOutput(lvlWarning, std::string(buf) + "\n");
    if (logOutputConsole)
        fprintf(stderr, "%s\n", buf);
}
#endif // DEBUG

void ePythonOutput(const char *string)
{
#ifdef DEBUG
    singleLock s(DebugLock);
    logOutput(lvlWarning, string);
    if (logOutputConsole)
        fwrite(string, 1, strlen(string), stderr);
#endif
}

void eWriteCrashdump()
{
        /* implement me */
}

Those fuctions should never be used at wild since they are ALWAYS active. I self even made errors against that into servicemp3.cpp (but with the patch corrected those).

 

It is really not for nothing that I just commented AND NOT REMOVED THE LINES. The patch is much more critical then some "dev's ???" think."

 

As for how it must be treated in future that must be discussed. But the ones  I did comment in the patch for servicemp3.cpp  do ALL cause problems and this on ALL boxes and this now .

[theparasol]

Yep agree serious shit!

But at first glance the lock might be the problem but isnt it the flood of log messages we feed to the debuglog function?

Did you already attempt / experiment to code something in debuglog like: if fresh debug line same as previous just skip it and do nothing!

[athoik]

Did you ever think that the GStreamer version you are using is sending too much information about buffering without a reason?

There is already a patch in 1.6 series that fixes that issue.

I guess you are using GStreamer Master branch, it is quite posible that they might introduce something that creates too many buffer change messages.

The eDebug was never a trouble as long as GStreamer is behaving correctly, does he?

Edited by athoik, 13 January 2016 - 22:04.

[christophecvr]

Did you ever think that the GStreamer version you are using is sending too much information about buffering without a reason?

There is already a patch in 1.6 series that fixes that issue.

I guess you are using GStreamer Master branch, it is quite posible that they might introduce something that creates too many buffer change messages.

The eDebug was never a trouble as long as GStreamer is behaving correctly, does he?

Actually it is just the eDebug(and all related ones see list above) which has been a problem since e2 exist. The cause is not the eDebug function as this is perfect and right. I'ts the use off it we make which is wrong.

 

Like the sand keeper till freeze, full freeze and lock or crash  for some media ok on duo2 faster but on dm8000 its just the same only a little less.

I really dicovered that one off the main cause in this situation even the only cause is line 2089.

 

After this discovery I really tested all sometimes at wild coming up problems with srt subtitles could come from this and they really DO. This have nothing to to with gstreamer self.

 

The problem are not the function and the parsing used in it who are causing problems but only and only the use off eDebug to print them in log if they are repetitive .

 

 

But ok I already understand the major issue is discovered and all core members are scared and want to be clean off any error they could have made in the past .

That's a unfortunate bad characteristic required to become a pli core member I noticed. Put You errors on a other, like yes gstreamer a good target or yes THE DRIVER IS WRONG ???

 

But if any core member can't see or even understand that rule 2089 is really wrong ???

That actually a lot of others are wrong and this cause the eDebug does run "ALWAYS" not only when You log into console or file

 

 

Well sorry .......................????????

[MastaG]

I've just gave Chris' patch a shot on my spark7162 receiver.

Without that buffering message the receiver is starting the streams almost instantly.

[athoik]

I did send a patch to GStreamer for sending too many bitrate changes, at first I patched Enigma instead of fixing the root cause.

What I am saying is really all those buffer change required?

Also if you send a minute to have a look at the bitrate patch you would notice that we are sending bitrate change when percentage delta changes (just like proposed above by mirakels i think).

Anyway i am trying to discuss, to point some other possible aspects. But you already made your mind.

Edited by athoik, 13 January 2016 - 23:20.

[christophecvr]

I've just gave Chris' patch a shot on my spark7162 receiver.

Without that buffering message the receiver is starting the streams almost instantly.

O nice. But I personally waisted my time here.

If the big Kings off pli (at last that’s what they think of themselves) remain blind to the facts it will never lead to anything and the error will be there even in the year 3000.

[MastaG]

Well I'm thankful.

This was the last thing that was really annoying me.

Lot's of movies I'm using have external .srt subtitles files.

I would occasionally get the spinner when e2 was trying to process/buffer/whatever with them.

That's now solved as well.

So I'm keeping the patch for my next (and probably last) round of images.

[christophecvr]

I did send a patch to GStreamer for sending too many bitrate changes, at first I patched Enigma instead of fixing the root cause.

What I am saying is really all those buffer change required?

Also if you send a minute to have a look at the bitrate patch you would notice that we are sending bitrate change when percentage delta changes (just like proposed above by mirakels i think).

Anyway i am trying to discuss, to point some other possible aspects. But you already made your mind.

Yes I saw that but this has really nothing to do with or current error into e2.

 

And to many bitrate changes ? If the media does has a real bitrate change it has a meaning since it really happened. This means is up to us to handle that issue ... We do not need to use a eDebug msg for that. Again the problem is NOT the parsing but the line  eDebug(bla bla bla) which cause the problem.

[mirakels]

chris, you may see us as kings but that won't help you or us in anyway. But if you see us as robots waiting for someone post a rant about a function that is perfectly sane (if it wasn't for this function enigma and enigma2 would not have been where it is today (in the sense that it evolved for the good, even if it is still far from perfect)), the you have lost!

 

If this eDebug in line #whatever# is causing issues because it is called to many times then fine, explain that and supply a patch for just that line. Don't bug about issues with the eDebug subsystem and post a patch that does much more than  just fixing that issue.

 

It has been told before, keep patches small, clean and well commented/documented  in a clear way 

(and without comments abusing your own name)