Created attachment 232585 [details] [review]
Use GLib for JS logging

Reserve our custom logging framework for debug logging, and use standard
g_log functions for log() and logError().
This allows us to finally have readable error messages, it associates
them with a program and process when necessary, and it prepares us
for a future where glib logs to the journal by default.

This is something I wanted to do for a looong time!

Review of attachment 232585 [details] [review]:

And I'm glad you found a vaguely related bug to do so!

::: gjs/jsapi-util.c
@@ +619,3 @@
     props_iter = JS_NewPropertyIterator(context, obj);
     if (props_iter == NULL) {
+        gjs_log_exception(context);

Seems like a bad translation?

@@ -728,3 @@
-void
-gjs_log_exception_props(JSContext *context,
-                        jsval      exc)

Could you take the changes you've made to this file that are separable and put them in their own patch, and then file a new bug for the rest of the changes?

This isn't about GLib warnings vs. our own warnings framework, it's about good warnings vs. absurdly silly warnings.

@@ +740,3 @@
+    if (utf8_message) {
+        if (utf8_stack)
+            g_warning("JS ERROR: %s: %s\n%s", utf8_message, utf8_exception, utf8_stack);

Not sure this is any better, bub.

Also, isn't there some GNU printf extension that allows conditional things, which would allow us to emit that colon only if utf8_message is truthy.

::: modules/jsUnit.js
@@ +372,3 @@
   top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'warn');
   top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'inform');
   top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'debug');

Unrelated changes to this file?

::: test/js/testCairo.js
@@ +172,3 @@
     o.connect('sig-with-foreign-struct', function(o, cr) {
         called = true;
+        assertEquals(_ts(cr), "CairoContext");

Unrelated.

(In reply to comment #2)
> Review of attachment 232585 [details] [review]:
> 
> And I'm glad you found a vaguely related bug to do so!
> 
> ::: gjs/jsapi-util.c
> @@ +619,3 @@
>      props_iter = JS_NewPropertyIterator(context, obj);
>      if (props_iter == NULL) {
> +        gjs_log_exception(context);
> 
> Seems like a bad translation?

Possibly. But a full exception message seems more useful than a generic failure message.

> @@ -728,3 @@
> -void
> -gjs_log_exception_props(JSContext *context,
> -                        jsval      exc)
> 
> Could you take the changes you've made to this file that are separable and put
> them in their own patch, and then file a new bug for the rest of the changes?
> 
> This isn't about GLib warnings vs. our own warnings framework, it's about good
> warnings vs. absurdly silly warnings.

Except they're not really separable. If I call gjs_debug(GJS_DEBUG_ERROR...) with the new strings I get

    JS ERROR: !!!   ReferenceError: ddd is not defined
    JS ERROR: !!!   @/home/lamefun/test/share/glicket/src/textView.js:32
wrapper()@/usr/share/gjs-1.0/lang.js:204
_parent((void 0))@/usr/share/gjs-1.0/lang.js:166
()@/home/lamefun/test/share/glicket/src/textView.js:13
wrapper()@/usr/share/gjs-1.0/lang.js:204
()@/home/lamefun/test/share/glicket/src/mainView.js:119
wrapper()@/usr/share/gjs-1.0/lang.js:204
()@/home/lamefun/test/share/glicket/src/main.js:100
wrapper()@/usr/share/gjs-1.0/lang.js:204
()@/home/lamefun/test/share/glicket/src/main.js:35
wrapper()@/usr/share/gjs-1.0/lang.js:204
start([object Array])@/home/lamefun/test/share/glicket/src/main.js:146
@<command line>:1

which is not a big improvement...

(compare to:

(gnome-shell-real:15894): Gjs-WARNING **: JS ERROR: Error: an error
@/opt/gnome/share/gnome-shell/js/ui/lookingGlass.js:1051
("logError(Error('an error'))")@/opt/gnome/share/gnome-shell/js/ui/lookingGlass.js:1051
wrapper("logError(Error('an error'))")@/opt/gnome/share/gjs-1.0/lang.js:204
([object GObject_Object])@/opt/gnome/share/gnome-shell/js/ui/lookingGlass.js:930

)

> @@ +740,3 @@
> +    if (utf8_message) {
> +        if (utf8_stack)
> +            g_warning("JS ERROR: %s: %s\n%s", utf8_message, utf8_exception,
> utf8_stack);
> 
> Not sure this is any better, bub.
> 
> Also, isn't there some GNU printf extension that allows conditional things,
> which would allow us to emit that colon only if utf8_message is truthy.

I guess 

> ::: modules/jsUnit.js
> @@ +372,3 @@
>    top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'warn');
>    top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'inform');
>    top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'debug');
> 
> Unrelated changes to this file?

Not really. The new exception logger assumes that exception stringify to something useful and have 'stack' property which is a string. Errors from the JS unit test framework had neither of these properties.

> ::: test/js/testCairo.js
> @@ +172,3 @@
>      o.connect('sig-with-foreign-struct', function(o, cr) {
>          called = true;
> +        assertEquals(_ts(cr), "CairoContext");
> 
> Unrelated.

Except that without the fix, the test suite doesn't run, because GLib warnings are fatal inside gtester.

(In reply to comment #3)
> Except they're not really separable. If I call gjs_debug(GJS_DEBUG_ERROR...)
> with the new strings I get
> 
>     JS ERROR: !!!   ReferenceError: ddd is not defined
>     JS ERROR: !!!   @/home/lamefun/test/share/glicket/src/textView.js:32
> wrapper()@/usr/share/gjs-1.0/lang.js:204
> _parent((void 0))@/usr/share/gjs-1.0/lang.js:166
> ()@/home/lamefun/test/share/glicket/src/textView.js:13
> wrapper()@/usr/share/gjs-1.0/lang.js:204
> ()@/home/lamefun/test/share/glicket/src/mainView.js:119
> wrapper()@/usr/share/gjs-1.0/lang.js:204
> ()@/home/lamefun/test/share/glicket/src/main.js:100
> wrapper()@/usr/share/gjs-1.0/lang.js:204
> ()@/home/lamefun/test/share/glicket/src/main.js:35
> wrapper()@/usr/share/gjs-1.0/lang.js:204
> start([object Array])@/home/lamefun/test/share/glicket/src/main.js:146
> @<command line>:1
> 
> which is not a big improvement...

I think it is.

> (compare to:
> 
> (gnome-shell-real:15894): Gjs-WARNING **: JS ERROR: Error: an error
> @/opt/gnome/share/gnome-shell/js/ui/lookingGlass.js:1051
> ("logError(Error('an
> error'))")@/opt/gnome/share/gnome-shell/js/ui/lookingGlass.js:1051
> wrapper("logError(Error('an error'))")@/opt/gnome/share/gjs-1.0/lang.js:204
> ([object
> GObject_Object])@/opt/gnome/share/gnome-shell/js/ui/lookingGlass.js:930
> 
> )

The only thing different is the prefix. Well, besides the two different stack traces.

> > ::: modules/jsUnit.js
> > @@ +372,3 @@
> >    top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'warn');
> >    top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'inform');
> >    top.xbDebugTraceFunction('top.testManager.containerTestFrame', 'debug');
> > 
> > Unrelated changes to this file?
> 
> Not really. The new exception logger assumes that exception stringify to
> something useful and have 'stack' property which is a string. Errors from the
> JS unit test framework had neither of these properties.

Well, land these changes first.

> > ::: test/js/testCairo.js
> > @@ +172,3 @@
> >      o.connect('sig-with-foreign-struct', function(o, cr) {
> >          called = true;
> > +        assertEquals(_ts(cr), "CairoContext");
> > 
> > Unrelated.
> 
> Except that without the fix, the test suite doesn't run, because GLib warnings
> are fatal inside gtester.

Yeah, this is an obvious bug. It deserves to have its own patch, not grouped in with random other changes.

Created attachment 243469 [details] [review]
Fix cairo test

We should check for equality, not truthiness.

Created attachment 243470 [details] [review]
Fix JSUnit to use regular exceptions objects

This way we can assume that all exceptions stringify to something
useful and have a valid .stack property, which is an assumption
we want to make for the new error logger.

Created attachment 243471 [details] [review]
Use GLib for JS logging

Reserve our custom logging framework for debug logging, and use standard
g_log functions for log() and logError().
This allows us to finally have readable error messages, it associates
them with a program and process when necessary, and it prepares us
for a future where glib logs to the journal by default.

Created attachment 243472 [details] [review]
Stop walking the stack manually

In JS 17, and when dealing with optimized frames without "arguments",
our technique to build the stack can fail and throw an exception.
Normally we would override it when we set the real exception, but
in the GDBus test suite we didn't, so there was always this
unnoticed "Debugger scope is not live" error, until it was made
fatal by glib changes.

Review of attachment 243469 [details] [review]:

OK.

Review of attachment 243470 [details] [review]:

OK.

Review of attachment 243471 [details] [review]:

OK.

Review of attachment 243472 [details] [review]:

::: gjs/stack.c
@@ +60,3 @@
+                        "Error", &v_constructor) ||
+        !JSVAL_IS_OBJECT(v_constructor)) {
+        JS_ReportError(context, "??? Missing Error constructor in global object?");

g_error. This is absolutely fatal.

@@ +64,3 @@
     }
 
+    /* throw new Error(message) */

"new Error(null)"

(In reply to comment #12)
> Review of attachment 243472 [details] [review]:
> 
> ::: gjs/stack.c
> @@ +60,3 @@
> +                        "Error", &v_constructor) ||
> +        !JSVAL_IS_OBJECT(v_constructor)) {
> +        JS_ReportError(context, "??? Missing Error constructor in global
> object?");
> 
> g_error. This is absolutely fatal.

I just copy-pasted from gjs_throw, but ok.

*** Bug 695718 has been marked as a duplicate of this bug. ***

Created attachment 243501 [details] [review]
Stop walking the stack manually

In JS 17, and when dealing with optimized frames without "arguments",
our technique to build the stack can fail and throw an exception.
Normally we would override it when we set the real exception, but
in the GDBus test suite we didn't, so there was always this
unnoticed "Debugger scope is not live" error, until it was made
fatal by glib changes.

Review of attachment 243501 [details] [review]:

::: gjs/stack.c
@@ +64,3 @@
     }
 
+    err_obj = JS_New(context, JSVAL_TO_OBJECT(v_constructor), 0, NULL);

Erm, you didn't have to remove the comment entirely.

Attachment 243469 [details] pushed as 8adde7c - Fix cairo test
Attachment 243470 [details] pushed as 61d3d45 - Fix JSUnit to use regular exceptions objects
Attachment 243471 [details] pushed as 9deaf85 - Use GLib for JS logging
Attachment 243501 [details] pushed as 6cdf959 - Stop walking the stack manually