Page MenuHomePhabricator

Lots of odd messages when running vim
Closed, ResolvedPublic

Description

I noticed this when running 'git bisect' to track down another problem...

When running vim, I get the following error messages printed to the controlling terminal (i.e. where I launched terminology from):

ERR<22499>:termpty termptyesc.c:1008 _handle_esc_csi() unhandled CSI 'n' (0x6e)
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo
ERR<22499>:termpty termptyesc.c:1187 _handle_esc_dcs() unhandled dsc request to get termcap/terminfo

I don't know if they mean much, but odds are they probably shouldn't be there, right?

gregkh created this task.Dec 4 2013, 9:09 PM
gregkh updated the task description. (Show Details)
gregkh raised the priority of this task from to Normal.
gregkh added a project: Terminology.
gregkh added a subscriber: gregkh.
billiob claimed this task.Dec 5 2013, 1:57 AM
raster added a subscriber: raster.Dec 5 2013, 3:32 AM

yeah - they shouldn't be there. it's debug to let us know some escape sequence isn't handled yet in the vt core and should be - we now know what app/situation needs/uses it and can test. :)

We don't support (yet) requests about termcap or terminfo. Unless you like to play with those files, the default values used by ncurses should work just fine.
I'll probably work on that after the release.

I can reproduce "unhandled dsc request to get termcap/terminfo" but not the first one when launching vim.

is this fixed by now? @billiob?

@raster: I only made terminology handle the CSI 'n'.
Termcap/terminfo still needs to be done. Vim still works perfectly without them.

aaah ok - si this is more a todo item for you still. cool.

billiob removed billiob as the assignee of this task.Jan 29 2015, 3:27 PM
billiob changed the visibility from "All Users" to "Public (No Login Required)".Dec 27 2015, 3:00 PM

Still shows up in 0.8.0 release, but bonus, you get a full traceback as well, making it look even worse :(

Here is what is going on:
there is a message about an escape code that terminology does not support ( experimental in xterm according to doc: http://invisible-island.net/xterm/ctlseqs/ctlseqs.html#h2-Device-Control-functions ( DCS + p Pt ST and DCS + q Pt ST) ). This should have no consequence on your usage of terminology.
Since some EFL release, any error message produces a backtrace. @raster might help on how to change that.

In commit 3a7238978e1048eca2b3ef309b945bf0a5ce53c1, I've changed those error messages to be only warnings. They should no longer produce any backtrace.

Seeing how old that commit is, it reminds me that I should make a new release of Terminology soon (well, I'll try to get it out before the end of the year).

cedric added a subscriber: cedric.Nov 15 2016, 2:12 PM

Oh, we still have backtrace always on for release mode. It was annoying for developers, and we disable it. The amount of bug report that come with a backtrace triggered by Eina_Log is super low, so I have turned that behavior off as it clearly annoy user without producing much help that we couldn't get by asking them to turn backtrace on manually when necessary.

seriously. stop turning the backtracing off. python backtraces out of the box for everyone. everyone is happy enough. you will ALWAYS get a complaint. if traces had been on by default before they would have been provided and likely the SOURCE of such issues would have been caught earlier and MANY other issues we have seen

@raster please point me to reported bug that have used the backtrace generated by Eina_Log. Backtrace for Eina_Log in release mode has been on since you have introduced that feature, I haven't seen any bug report with it. We have turned off backtrace for Eina_Log in git as they were annoying every developers, they do also annoy, scare and confuse users with no benefit.

it's used by people figuring out which thing in THEIR app did something wrong. we don't get reports with bt logs because YOU TURNED IT OFF BY DEFAULT and the majority of people reporting bugs report them against git builds not against releases. if it scares someone It SHOULD - it's an error. fix the error and stop avoiding it.

you turn it off here because @gregkh (one person) says "it's ugly". he's not the one trying to find where the issue happened and had this been a far less technically savvy user explaining how to enable it, then reproduce the issue etc. is a whole bunch of hurt that is not needed. i see issues happen all the time and its far too late to set the env var by the time you see it - it takes extra time and effort to figure out how to reproduce and then finally get it.

if the kernel stops dumping every register, a call trace, etc in oopses, python stops providing bt's on python errors THEN i might believe you that people do truly hate this kind of thing MORE than it is useful. get greg to disable oops verbosity in the kernel by default unless you pass some kernel boot param ... you may have a point if that gets accepted as a worthwhile trade-off. but EXTRA information that helps diagnose an issue is almost never a bad idea. so what if it is long? then you have longer log output when it happens? so what? the ERROR should not be happening to begin with. or it shouldn't be an error and more likely a warning or debug.

I turned it off today. It has been on in every single release of efl since you added the code. I turned it off because there has been a continuous complain on this by everyone for years now and I have seen no result from it. The issue is that it makes Eina_Log useless for logging as the error message become unreadable by users.

people always complain about what doesn't interest them. but then the complaint turns into "why don't you fix the bug?" ... because they don't provide the trace. it's OFF by default in git builds and that means most people who are reporting bugs don't ever see it.

if there are so many errors that the bt's matter then the issuer is with the errors not the bt's. if users complain but then don't provide the bt - is the issue with the bt? is it that they don't provide it because they THINK it shouldn't be provided? but just turning it off is not a solution. having to then turn it on is an exercise the least technical people are least likely to be able to do and they are the ones we need it from most.

let me give you an example right now spewing out of my `/.xsession-errors ... i have turned bt's on because otherwise i would be unable to find this at all:

ERR<1161>:elementary lib/elementary/elm_widget.c:1144 elm_widget_sub_object_parent_add() You passed a wrong parent parameter (0x4000002ad6094cd4 edje). Elementary widget's parent should be an elementary widget.

ok. go on. where is the bug? elm_widget.c... yay! that's really useful. it's entirely useless. we have 1000's of such errors across efl that will not tell you SQUAT on where the issue really is because a calls b calls c. a user reporting this has reported an unfixable bug. in fact they don't tend to report it because their WM didn't crash thus they just report nothing. make things abort on error and i guarantee you will see a change. but since this is off by default, you can't find out the real source. let me give you the btlog:

/usr/local/lib/libeina.so.1	 0x7f1097723bb6 0x7f10976fd000
/usr/local/lib/libeina.so.1	 0x7f1097724823 0x7f10976fd000
/usr/local/lib/libeina.so.1	 0x7f1097725cb7 0x7f10976fd000
/usr/local/lib/libelementary.so.1	 0x7f10a0adeada 0x7f10a0884000
/usr/local/lib/libelementary.so.1	 0x7f10a0a9bc36 0x7f10a0884000
/usr/local/lib/libevas.so.1	 0x7f109cd6d73d 0x7f109ccd9000
/usr/local/lib/libevas.so.1	 0x7f109cd6fce4 0x7f109ccd9000
/usr/local/lib/libeo.so.1	 0x7f109798e237 0x7f109797f000
/usr/local/lib/libelementary.so.1	 0x7f10a0adfd1b 0x7f10a0884000
/usr/local/lib/libeo.so.1	 0x7f109798e237 0x7f109797f000
/usr/local/lib/libelementary.so.1	 0x7f10a0a4981f 0x7f10a0884000
/usr/local/lib/libeo.so.1	 0x7f109798e237 0x7f109797f000
/usr/local/lib/libelementary.so.1	 0x7f10a0a9c6dc 0x7f10a0884000
/usr/local/lib/libeo.so.1	 0x7f109798e237 0x7f109797f000
/usr/local/lib/libeo.so.1	 0x7f109798919b 0x7f109797f000
/usr/local/lib/libelementary.so.1	 0x7f10a0a9a65b 0x7f10a0884000
/usr/local/bin/enlightenment	 0x4631a0 0x400000
/usr/local/bin/enlightenment	 0x470620 0x400000
/usr/local/bin/enlightenment	 0x462d7c 0x400000
/usr/local/lib/enlightenment/modules/mixer/linux-gnu-x86_64-ver-0.22/module.so	0x7f107b9e0290 0x7f107b9d8000
/usr/local/lib/enlightenment/modules/mixer/linux-gnu-x86_64-ver-0.22/module.so	0x7f107b9e2e48 0x7f107b9d8000
/usr/lib/libpulse.so.0	 0x7f107b59d3b5 0x7f107b582000
/usr/lib/pulseaudio/libpulsecommon-9.0.so	 0x7f1079d90a01 0x7f1079d51000
/usr/lib/pulseaudio/libpulsecommon-9.0.so	 0x7f1079d90d8b 0x7f1079d51000
/usr/lib/libpulse.so.0	 0x7f107b592c0e 0x7f107b582000
/usr/lib/pulseaudio/libpulsecommon-9.0.so	 0x7f1079d93837 0x7f1079d51000
/usr/lib/pulseaudio/libpulsecommon-9.0.so	 0x7f1079d9648b 0x7f1079d51000
/usr/lib/pulseaudio/libpulsecommon-9.0.so	 0x7f1079d96829 0x7f1079d51000
/usr/lib/pulseaudio/libpulsecommon-9.0.so	 0x7f1079d970aa 0x7f1079d51000
/usr/local/lib/enlightenment/modules/mixer/linux-gnu-x86_64-ver-0.22/module.so	0x7f107b9e52be 0x7f107b9d8000
/usr/local/lib/libecore.so.1	 0x7f10992c1f5a 0x7f10992a8000
/usr/local/lib/libecore.so.1	 0x7f10992c2616 0x7f10992a8000
/usr/local/bin/enlightenment	 0x43ac7d 0x400000
/usr/lib/libc.so.6	 0x7f109640b291 0x7f10963eb000
/usr/local/bin/enlightenment	 0x43beea 0x400000

NOW we begin to see just how deep the rabbit hole goes.

                                                      /usr/local/lib/libeina.so.1          |                            /home/raster/C/efl/src/lib/eina/eina_log.c            : 2106 @ eina_log_print_cb_journald()
                                                      /usr/local/lib/libeina.so.1          |                            /home/raster/C/efl/src/lib/eina/eina_inline_log.x     :  167 @ eina_log_level_color_get()
                                                      /usr/local/lib/libeina.so.1          |                            /home/raster/C/efl/src/lib/eina/eina_log.c            : 2030 @ eina_log_domain_registered_level_set()
                                                      /usr/local/lib/libelementary.so.1    |                      /home/raster/C/efl/src/lib/elementary/elm_widget.c          : 1036 @ elm_widget_theme_specific()
                                                      /usr/local/lib/libelementary.so.1    |                      /home/raster/C/efl/src/lib/elementary/elm_slider.c          :  323 @ _indicator_set()
                                                      /usr/local/lib/libevas.so.1          |              /home/raster/C/efl/src/../src/lib/evas/canvas/efl_canvas_group.eo.c :   44 @ efl_canvas_group_add()
                                                      /usr/local/lib/libevas.so.1          |                     /home/raster/C/efl/src/lib/evas/canvas/evas_object_smart.c   : 1456 @ evas_object_smart_init()
                                                      /usr/local/lib/libeo.so.1            |                              /home/raster/C/efl/src/lib/eo/efl_object.eo.c       :   86 @ efl_constructor()
                                                      /usr/local/lib/libelementary.so.1    |                      /home/raster/C/efl/src/lib/elementary/elm_widget.c          : 6099 @ _elm_widget_efl_object_provider_find()
                                                      /usr/local/lib/libeo.so.1            |                              /home/raster/C/efl/src/lib/eo/efl_object.eo.c       :   86 @ efl_constructor()
                                                      /usr/local/lib/libelementary.so.1    |                     /home/raster/C/efl/src/../src/lib/eina/eina_inline_value.x   : 1739 @ eina_value_type_flush()
                                                      /usr/local/lib/libeo.so.1            |                              /home/raster/C/efl/src/lib/eo/efl_object.eo.c       :   86 @ efl_constructor()
                                                      /usr/local/lib/libelementary.so.1    |                      /home/raster/C/efl/src/lib/elementary/elm_slider.c          :  948 @ _spacer_down_cb()
                                                      /usr/local/lib/libeo.so.1            |                              /home/raster/C/efl/src/lib/eo/efl_object.eo.c       :   86 @ efl_constructor()
                                                      /usr/local/lib/libeo.so.1            |                              /home/raster/C/efl/src/lib/eo/eo.c                  :  765 @ _efl_add_internal_start()
                                                      /usr/local/lib/libelementary.so.1    |                      /home/raster/C/efl/src/lib/elementary/elm_slider.eo.c       :  217 @ elm_slider_class_get()
                                                      /usr/local/bin/enlightenment         |                                   /home/raster/C/e/src/bin/e_client_volume.c     :  328 @ e_client_volume_object_add()
                                                      /usr/local/bin/enlightenment         |                                   /home/raster/C/e/src/bin/e_comp_object.c       : 3290 @ e_comp_object_frame_volume_update()
                                                      /usr/local/bin/enlightenment         |                                   /home/raster/C/e/src/bin/e_client_volume.c     :  221 @ e_client_volume_sink_append()
/usr/local/lib/enlightenment/modules/mixer/linux-gnu-x86_64-ver-0.22/module.so             |                         /home/raster/C/e/src/modules/mixer/e_mod_main.c          :  934 @ _sink_input_event()
/usr/local/lib/enlightenment/modules/mixer/linux-gnu-x86_64-ver-0.22/module.so             |                             /usr/local/include/eina-1/eina/eina_inline_list.x    :   32 @ eina_list_next()
                                                            /usr/lib/libpulse.so.0         |                                                         ??/??                    :   32 @ pa_format_info_set_prop_string_array()
                                                 /usr/lib/pulseaudio/libpulsecommon-9.0.so |                                                         ??/??                    :   32 @ pa_pdispatch_ref()
                                                 /usr/lib/pulseaudio/libpulsecommon-9.0.so |                                                         ??/??                    :   32 @ pa_pdispatch_run()
                                                            /usr/lib/libpulse.so.0         |                                                         ??/??                    :   32 @ pa_context_unref()
                                                 /usr/lib/pulseaudio/libpulsecommon-9.0.so |                                                         ??/??                    :   32 @ pa_pstream_register_memfd_mempool()
                                                 /usr/lib/pulseaudio/libpulsecommon-9.0.so |                                                         ??/??                    :   32 @ pa_pstream_unref()
                                                 /usr/lib/pulseaudio/libpulsecommon-9.0.so |                                                         ??/??                    :   32 @ pa_pstream_unref()
                                                 /usr/lib/pulseaudio/libpulsecommon-9.0.so |                                                         ??/??                    :   32 @ pa_random()
/usr/local/lib/enlightenment/modules/mixer/linux-gnu-x86_64-ver-0.22/module.so             | /home/raster/C/e/src/modules/mixer/lib/backends/pulseaudio/pulse_ml.c            :   78 @ _ecore_io_wrapper()
                                                      /usr/local/lib/libecore.so.1         |                           /home/raster/C/efl/src/lib/ecore/ecore_main.c          : 1983 @ _ecore_main_fd_handlers_call()
                                                      /usr/local/lib/libecore.so.1         |                           /home/raster/C/efl/src/lib/ecore/ecore_main.c          : 2355 @ _ecore_main_loop_iterate_internal()
                                                      /usr/local/bin/enlightenment         |                                   /home/raster/C/e/src/bin/e_main.c              : 1097 @ main()
                                                            /usr/lib/libc.so.6             |                                                         ??/??                    : 1097 @ __libc_start_main()
                                                      /usr/local/bin/enlightenment         |                                                         ??/??                    :    0 @ _start()

the ACTUAL problem is way way way up the stack in e_client_volume_object_add(). good luck getting people to set env vars for their window manager/desktop env when they don't even know how it is run (run from a xsession desktop file by their display manager). you cant change _backtrace_level with env vars that e sets itself because these are set after eina_init because e has to load config first to be able to do so... either way by having bt's off users could never provide a useful report. maybe they don't think they should provide them? maybe that's the issue. maybe the issue is you and many other devs just never use them thus you THINK they are useless. maybe you just dislike fixing errors or you use eina error logs instead of a printf and thus error level is used to get an always there complaint because errors are displayed by default. as i said - maybe it should be a warn or debug not an error. errors are bad things that should be fixed and may/will lead to unexpected side effects were they not there. i suspect that the issue is that devs are still using eina error abort and thus find this useless, but that fact we have these errors often enough says that this is obviously such a pain to do no one is fixing them ... so instead... they are ignoring them and instead "lets just make the error a 1 liner so i can ignore it more easily" is a better solution. that's not a solution. it's sticking your head in the sand.

as i said - if python dropped it's backtraces (unless you set sme env var) or kernel oopses were 1 liners without a kernel boot param i might believe that in the popularity contest of utility vs "undesired noise" the undesired noise wins at expense of fixing issues.

stop watering down debug info. errors annoy me too but instead of shutting eina log up ... i fix the problem. i have at least 1 pending commit i have locally that does exactly that and i FOUND the error by using the bt log.

So I spend some times looking at all our past and current ticket in phab. There are 4 tickets I could find with a backtrace generated with this macro and only one ticket where someone used eina_btlog to actually convert the backtrace to a readable form. This is over the course of at least a year where this feature was turned on.

I am not denying that this feature might be useful, but it is to a small number of people that are actually debugging something and this people can selectively turn it on when they need and want it. If you really want to have it always on for yourself, I can add a configure option for that purpose.

What about an option in the builds like --build-type=stable or --build-type=development (so the default will be development) where in the stable mode, all the debug and messages are turned off, and the development all the information about reports are on ?

i can set an env var. i am not talking about myself. i do set the env vars in my env. i am personally not affected by this.

my point is the people who need this on by default are those that don't know how to set the env var or can't or don't even know one exists so they can't or don't provide the info as its just not there BY DEFAULT.

this is not about arguing about there being an option - the env var exists at runtime - the option is already there. the issue is for it being ON by default.

i added this feature EXPLICITLY because of this reasons - people complaining how pointless out error logs were as they were logging errors and they had no idea WHERE as the where was inside efl and the src was higher up the stack. complaining that python provides USEFUL error logs but efl's are useless and thus just annoying noise. they had no idea EINA_LOG_ERROR_ABORT existed and frankly they don't care. sthey should not HAVE to know IF we can provide the info for them. we CAN. i spent the time finding a way to do this with unwind + btlog. if they don't know a switch/option exists and have to ask questions or read docs then it's far too late. THAT is why you dont see these logs because its off by default in git buiulds thus MOSt reporters are not providing them.

the bt info should be presented FIRST by DEFAULT. at least for actual errors that should be fixed. by turning it OFF by default you basically neutered the whole point of this - to NOT have to force people to learn more, read more, know how to set up env vars, run stuff under gdb to collect bt's etc.

i have a pending commit that adds instructions on how to convert it to human readable form in the log. i COULD do popen etc. but this is a lot more costly and this is not something i want to do unless errors are really rare. at least some instructions will mean people use eina_btlog to make these things readable out of the box ... or know HOW. popen() is probably a step too far atm.

switch things from ERR to WRN or DBG if this is an actual issue and "so so so much noise". that is the right solution and have bt's only on ERR level... (by default).

at the moment in dev mode these bt's are off because efl devs just don't want to see the logs at all. my take is that means they just don't want to fix the issues and so "shut up" is the solution. they COULD set an env var to turn it off. but it should be ON by default SO reports provide as much info as possible to track down the problem and fix it.

Um, please don't turn off backtraces because of me, I'm not objecting to them at all.

I was just commenting that a long time ago (when I first filed this bug), there were less messages (i.e. no backtrace) than there is today (same warnings, more backtrace), that was all.

If it will enable the bug/error to be fixed easier, great, leave it alone, it might cause people to report more issues and find the problem easier.

Now if someone could fix the original warning messages, I would be most happy :)

billiob closed this task as Resolved.Mar 10 2018, 11:08 AM
billiob claimed this task.

It seems the original issue has been handled a long time ago.