After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 792210 - Improvements to the GSD power test
Improvements to the GSD power test
Status: RESOLVED FIXED
Product: gnome-settings-daemon
Classification: Core
Component: power
unspecified
Other All
: Normal normal
: ---
Assigned To: gnome-settings-daemon-maint
gnome-settings-daemon-maint
Depends on:
Blocks:
 
 
Reported: 2018-01-04 16:35 UTC by Benjamin Berg
Modified: 2018-01-15 16:22 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
power: Set correct environment variable during testing (931 bytes, patch)
2018-01-04 16:35 UTC, Benjamin Berg
none Details | Review
power: Set G_MESSAGES_DEBUG during testing to force debug printing (929 bytes, patch)
2018-01-04 16:36 UTC, Benjamin Berg
needs-work Details | Review
power: Fix test access of logind mock object (2.07 KB, patch)
2018-01-04 16:36 UTC, Benjamin Berg
none Details | Review
power: Create XDG_RUNTIME_DIR to fix a warning from dbus on test startup (1.13 KB, patch)
2018-01-04 16:36 UTC, Benjamin Berg
none Details | Review
power: Add helper to read plugin log during test (4.39 KB, patch)
2018-01-04 16:36 UTC, Benjamin Berg
none Details | Review
power: Update tests to upower 1.0 (11.40 KB, patch)
2018-01-04 16:36 UTC, Benjamin Berg
needs-work Details | Review
power: Ensure test does not try to close the lid early (2.47 KB, patch)
2018-01-04 16:36 UTC, Benjamin Berg
none Details | Review
power: Wait for GSD to setup activity watch during testing (2.17 KB, patch)
2018-01-04 16:36 UTC, Benjamin Berg
needs-work Details | Review
power: Work around output buffering in gsd-power test (2.04 KB, patch)
2018-01-04 16:36 UTC, Benjamin Berg
needs-work Details | Review
power: Set correct environment variable during testing (1.02 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
power: Set --verbose during testing to force debug printing (1.09 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
power: Fix test access of logind mock object (2.14 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
power: Create XDG_RUNTIME_DIR to fix a warning from dbus on test startup (1.13 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
power: Add helper to read plugin log during test (1.67 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
power: Update tests to newer upower (11.26 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
power: Ensure test does not try to close the lid early (2.47 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
power: Wait for g-s-d to setup activity watch during testing (2.33 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
none Details | Review
power: Simplify test code by using the check_plugin_log helper (3.39 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
common: Work around output buffering for g_debug (2.60 KB, patch)
2018-01-11 16:42 UTC, Benjamin Berg
committed Details | Review
power: Wait for g-s-d to setup activity watch during testing (2.55 KB, patch)
2018-01-15 16:10 UTC, Benjamin Berg
committed Details | Review

Description Benjamin Berg 2018-01-04 16:35:54 UTC
Here is a bunch of improvements and fixes to the GSD power test. For me all the tests are passing at this point.
Comment 1 Benjamin Berg 2018-01-04 16:35:58 UTC
Created attachment 366311 [details] [review]
power: Set correct environment variable during testing

The test was setting GSD_MOCK but the C code checked GSD_MOCKED. Fix
this by using GSD_MOCKED in all cases.
Comment 2 Benjamin Berg 2018-01-04 16:36:04 UTC
Created attachment 366312 [details] [review]
power: Set G_MESSAGES_DEBUG during testing to force debug printing

Otherwise debug information may not be printed making testing
impossible.
Comment 3 Benjamin Berg 2018-01-04 16:36:09 UTC
Created attachment 366313 [details] [review]
power: Fix test access of logind mock object

The logind object attribute was renamed when moving to the dbusmock
template rather than using something custom. Update the tests to reflect
this.
Comment 4 Benjamin Berg 2018-01-04 16:36:15 UTC
Created attachment 366314 [details] [review]
power: Create XDG_RUNTIME_DIR to fix a warning from dbus on test startup

When starting the tests dbus would print a warning as the
XDG_RUNTIME_DIR was not yet created. Simply create this directory to
prevent the warning from being printed.

dbus[2514]: Unable to set up transient service directory: XDG_RUNTIME_DIR "/tmp/gsd-power-testjFVT_p/runtime" not available: No such file or directory
Comment 5 Benjamin Berg 2018-01-04 16:36:21 UTC
Created attachment 366315 [details] [review]
power: Add helper to read plugin log during test

Add a generic helper to find needles in the gsd-power plugin log instead
of implementing the loop in each case.
Comment 6 Benjamin Berg 2018-01-04 16:36:27 UTC
Created attachment 366316 [details] [review]
power: Update tests to upower 1.0

The new API has a composite device and GSD uses that rather than
collecting the information itself. Also, upower now does the critical
action rather than GSD meaning that we can only check for the
notification.

Remove/Update the tests to reflect these changes.
Comment 7 Benjamin Berg 2018-01-04 16:36:32 UTC
Created attachment 366317 [details] [review]
power: Ensure test does not try to close the lid early

GSD waits a while before a lid close action can affect anything. As the
setup routine updates the monitors, this safety timeout will be taken
into account.

This could cause rare test failures if the initialisation was too quick.
Add the explicit sleep to prevent any errors.
Comment 8 Benjamin Berg 2018-01-04 16:36:37 UTC
Created attachment 366318 [details] [review]
power: Wait for GSD to setup activity watch during testing

Some tests create activity just after the screen is blanked. There is a
race condition as setting up the active monitor may only be done after
the idle time has been reset.
Prevent this by adding a short sleep. This race is inherent to
GnomeIdleMonitor.
Comment 9 Benjamin Berg 2018-01-04 16:36:42 UTC
Created attachment 366319 [details] [review]
power: Work around output buffering in gsd-power test

During testing debug output is enabled using G_MESSAGES_DEBUG=all.
Unfortunately the default logging handler in GLib is not flushing the
output stream for each log message. In addition, the default buffering
for stdout seems to be block based (not line based) if stdout is not a
TTY.
This causes the log message to get stuck in the buffer and the tests
cannot read them.
Comment 10 Bastien Nocera 2018-01-11 13:39:40 UTC
Review of attachment 366311 [details] [review]:

Please reference 5fc7cb646bcae91d80d0aa90ab5fdd0fc8f513a6 where this bug was introduced (envvar/compile-time define confusion)
Comment 11 Bastien Nocera 2018-01-11 13:53:54 UTC
Review of attachment 366312 [details] [review]:

::: plugins/power/test.py
@@ +93,3 @@
         # Disable PulseAudio output from libcanberra
         env['CANBERRA_DRIVER'] = 'null'
+        env['G_MESSAGES_DEBUG'] = 'all'

Use --verbose instead, that's in daemon's options.

This broke in 198f7ea20352a2e46bb517a55bd80111fd192765 when we split off gnome-settings-daemon and gsd-power wasn't just a debug program, but a full fledged part of the session.
Comment 12 Bastien Nocera 2018-01-11 13:55:29 UTC
Review of attachment 366313 [details] [review]:

Sure. Bug introduced in commit f581667b187b38ff45f27e6eba62f30482fba1ee
Comment 13 Bastien Nocera 2018-01-11 13:56:48 UTC
Review of attachment 366314 [details] [review]:

Is this a regression in dbus? Would be nice to know...
Comment 14 Bastien Nocera 2018-01-11 13:58:51 UTC
Review of attachment 366315 [details] [review]:

This should be one of the last patches in the patchset, so that tests pass before and after those changes.
Comment 15 Bastien Nocera 2018-01-11 14:08:46 UTC
Review of attachment 366316 [details] [review]:

> Also, upower now does the critical
> action rather than GSD

"does the critical action"? It was already "doing the critical action". This should be clearer.

::: plugins/power/test.py
@@ +60,3 @@
         # start mock upowerd
         (self.upowerd, self.obj_upower) = self.spawn_server_template(
+            'upower', {'DaemonVersion': '1.0', 'OnBattery': True, 'LidIsClosed': False}, stdout=subprocess.PIPE)

No need to change that. In dbusmock:
> This provides the 0.9 D-BUS API of upower by default, but if the
> DaemonVersion property (in parameters) is set to >= 0.99 it will provide the
> 1.0 D-BUS API instead.

Given that the current versions are still in the 0.99 range...

@@ +210,3 @@
 
+    def set_composite_battery_discharging(self, icon='composite-battery-discharging'):
+        # type 2: battery

Those should be symbolic names. libupower-glib should have them, otherwise there's goo to generate .py files with that info in the same directory.
Comment 16 Bastien Nocera 2018-01-11 14:12:09 UTC
Review of attachment 366317 [details] [review]:

Sure.
Comment 17 Bastien Nocera 2018-01-11 14:14:25 UTC
Review of attachment 366318 [details] [review]:

By the way, it's g-s-d or gnome-settings-daemon, not GSD (except in symbols/constants)

::: plugins/power/test.py
@@ +399,3 @@
         self.check_blank(2)
 
+        # XXX: GSD may need a bit longer to setup the activity watch

Why not add a debug output when the activity watch is setup, and what for that, instead of possibly inaccurate timeouts?
Comment 18 Bastien Nocera 2018-01-11 14:16:23 UTC
Review of attachment 366319 [details] [review]:

Can you please ask GLib maintainers how to handle this correctly?
My guess is that it would be possible to make the change in daemon-skeleton*.h when verbose is set.
Comment 19 Benjamin Berg 2018-01-11 14:25:26 UTC
(In reply to Bastien Nocera from comment #13)
> Review of attachment 366314 [details] [review] [review]:
> 
> Is this a regression in dbus? Would be nice to know...

Good question. I suspect the warning may have always been there all along. It is harmless and I only saw it because everything was horribly failing for me at the time.

(In reply to Bastien Nocera from comment #18)
> Can you please ask GLib maintainers how to handle this correctly?
> My guess is that it would be possible to make the change in
> daemon-skeleton*.h when verbose is set.

Matthias was rather non-committal on IRC. But yes, working around in the skeleton is probably saner. I'll update the patch and see if I can find/open a bug about enhancing GLib.
Comment 20 Benjamin Berg 2018-01-11 16:42:04 UTC
Created attachment 366664 [details] [review]
power: Set correct environment variable during testing

The test was setting GSD_MOCK but the C code checked GSD_MOCKED. Fix
this by using GSD_MOCKED in all cases.

This fixes a regression introduced in commit 5fc7cb64 (power: Make power
plugin "mock" support a run-time check).
Comment 21 Benjamin Berg 2018-01-11 16:42:10 UTC
Created attachment 366665 [details] [review]
power: Set --verbose during testing to force debug printing

Otherwise debug information may not be printed making testing
impossible.

This regression was introduced in commit 198f7ea
(plugins: Rename sources of all test applications).
Comment 22 Benjamin Berg 2018-01-11 16:42:16 UTC
Created attachment 366666 [details] [review]
power: Fix test access of logind mock object

The logind object attribute was renamed when moving to the dbusmock
template rather than using something custom. Update the tests to reflect
this. This happened in commit f581667b (tests: Use existing logind template).
Comment 23 Benjamin Berg 2018-01-11 16:42:22 UTC
Created attachment 366667 [details] [review]
power: Create XDG_RUNTIME_DIR to fix a warning from dbus on test startup

When starting the tests dbus would print a warning as the
XDG_RUNTIME_DIR was not yet created. Simply create this directory to
prevent the warning from being printed.

dbus[2514]: Unable to set up transient service directory: XDG_RUNTIME_DIR "/tmp/gsd-power-testjFVT_p/runtime" not available: No such file or directory
Comment 24 Benjamin Berg 2018-01-11 16:42:27 UTC
Created attachment 366668 [details] [review]
power: Add helper to read plugin log during test

Add a generic helper to find needles in the gsd-power plugin log.
Comment 25 Benjamin Berg 2018-01-11 16:42:33 UTC
Created attachment 366669 [details] [review]
power: Update tests to newer upower

The new API has a composite device and g-s-d uses that rather than
collecting the information itself. Also, upower is doing the critical
action rather than g-s-d meaning that we can only check for the
notification.

Remove/Update the tests to reflect these changes.
Comment 26 Benjamin Berg 2018-01-11 16:42:40 UTC
Created attachment 366670 [details] [review]
power: Ensure test does not try to close the lid early

GSD waits a while before a lid close action can affect anything. As the
setup routine updates the monitors, this safety timeout will be taken
into account.

This could cause rare test failures if the initialisation was too quick.
Add the explicit sleep to prevent any errors.
Comment 27 Benjamin Berg 2018-01-11 16:42:46 UTC
Created attachment 366671 [details] [review]
power: Wait for g-s-d to setup activity watch during testing

Some tests create activity just after the screen is blanked. There is a
race condition as setting up the active monitor may only be done after
the idle time has been reset.
Prevent this by adding a short sleep. This race is inherent to
GnomeIdleMonitor.

Note that the race condition is actually between the call to
gnome_idle_monitor_add_user_active_watch and mutter receiving the dbus
method call.
Comment 28 Benjamin Berg 2018-01-11 16:42:52 UTC
Created attachment 366672 [details] [review]
power: Simplify test code by using the check_plugin_log helper

Use the helper introduced earlier instead of re-implementing the loop for
every function to test the gsd-power log. The helper was introduced in
the commit "power: Add helper to read plugin log during test".
Comment 29 Benjamin Berg 2018-01-11 16:42:59 UTC
Created attachment 366673 [details] [review]
common: Work around output buffering for g_debug

During testing debug output is enabled using --verbose.
Unfortunately the default logging handler in GLib is not flushing the
utput stream for each log message. In addition, the default buffering
for stdout seems to be block based (not line based) if stdout is not a
TTY.
This causes the log message to get stuck in the buffer and the tests
cannot read them.
Comment 30 Benjamin Berg 2018-01-11 16:58:20 UTC
(In reply to Bastien Nocera from comment #17)
> @@ +399,3 @@
>          self.check_blank(2)
>  
> +        # XXX: GSD may need a bit longer to setup the activity watch
> 
> Why not add a debug output when the activity watch is setup, and what for
> that, instead of possibly inaccurate timeouts?

That doesn't work. I clarified the comment a bit, but the race is actually the delivery of DBus message to add the watch.
Comment 31 Bastien Nocera 2018-01-13 01:27:09 UTC
Review of attachment 366664 [details] [review]:

Looks good.
Comment 32 Bastien Nocera 2018-01-13 01:27:32 UTC
Review of attachment 366665 [details] [review]:

Yep.
Comment 33 Bastien Nocera 2018-01-13 01:27:55 UTC
Review of attachment 366666 [details] [review]:

LGTM
Comment 34 Bastien Nocera 2018-01-13 01:28:18 UTC
Review of attachment 366667 [details] [review]:

Sure.
Comment 35 Bastien Nocera 2018-01-13 01:28:38 UTC
Review of attachment 366668 [details] [review]:

Sure.
Comment 36 Bastien Nocera 2018-01-13 01:34:09 UTC
Review of attachment 366669 [details] [review]:

::: plugins/power/test.py
@@ +212,3 @@
         GLib.file_set_contents ('GSD_MOCK_EXTERNAL_MONITOR', val)
 
+    def set_composite_battery_discharging(self, icon='composite-battery-discharging'):

Are you sure about those icon names? Those are the used names:
https://cgit.freedesktop.org/upower/tree/src/up-device.c#n93

Not sure it matters for this particular test though, in which case you might as well as "" as the icon...

@@ +788,3 @@
+                                      # UP_DEVICE_KIND_MOUSE
+                                      'Type': dbus.UInt32(5, variant_level=1),
+                                      'WarningLevel': dbus.UInt32(1, variant_level=1),

As long as you're modifying those lines, can you use the symbolic names?

@@ +804,3 @@
                      dbus_interface=dbus.PROPERTIES_IFACE)
+        obj_bat2.Set('org.freedesktop.UPower.Device', 'WarningLevel',
+                     dbus.UInt32(4, variant_level=1),

Ditto.
Comment 37 Bastien Nocera 2018-01-13 01:34:30 UTC
Review of attachment 366670 [details] [review]:

Sure.
Comment 38 Bastien Nocera 2018-01-13 01:35:33 UTC
Review of attachment 366671 [details] [review]:

::: plugins/power/test.py
@@ -437,3 @@
         self.check_blank(2)
 
-        # wiggle the mouse now and check for unblank; this is expected to pop up

Any reason why you're removing the explanations though?
Comment 39 Bastien Nocera 2018-01-13 01:36:29 UTC
Review of attachment 366673 [details] [review]:

You can add the line:
See https://bugzilla.gnome.org/show_bug.cgi?id=792432
in the commit message as well.

Looks good otherwise.
Comment 40 Bastien Nocera 2018-01-13 01:37:18 UTC
Review of attachment 366672 [details] [review]:

Can you replace the commit name in the log to also include the sha once you've committed it?
Looks good otherwise.
Comment 41 Benjamin Berg 2018-01-15 16:10:17 UTC
Created attachment 366844 [details] [review]
power: Wait for g-s-d to setup activity watch during testing

Some tests create activity just after the screen is blanked. There is a
race condition as setting up the active monitor may only be done after
the idle time has been reset.
Prevent this by adding a short sleep. This race is inherent to
GnomeIdleMonitor.

Note that the race condition is actually between the call to
gnome_idle_monitor_add_user_active_watch and mutter receiving the dbus
method call.
Comment 42 Bastien Nocera 2018-01-15 16:12:07 UTC
Review of attachment 366844 [details] [review]:

Looks fine.
Comment 43 Benjamin Berg 2018-01-15 16:21:27 UTC
Attachment 366664 [details] pushed as 18ee6cd - power: Set correct environment variable during testing
Attachment 366665 [details] pushed as 8b92770 - power: Set --verbose during testing to force debug printing
Attachment 366666 [details] pushed as 9725d89 - power: Fix test access of logind mock object
Attachment 366667 [details] pushed as 9701a4a - power: Create XDG_RUNTIME_DIR to fix a warning from dbus on test startup
Attachment 366668 [details] pushed as 450a936 - power: Add helper to read plugin log during test
Attachment 366669 [details] pushed as d98e5e0 - power: Update tests to newer upower
Attachment 366670 [details] pushed as 75551e6 - power: Ensure test does not try to close the lid early
Attachment 366672 [details] pushed as 9ad0468 - power: Simplify test code by using the check_plugin_log helper
Attachment 366673 [details] pushed as dee9a77 - common: Work around output buffering for g_debug
Attachment 366844 [details] pushed as 975d901 - power: Wait for g-s-d to setup activity watch during testing