730363 - startup slowdown waiting for batteryinfo

Status: RESOLVED FIXED

(Firefox OS Graveyard :: General, defect)

Description

[[:fabrice] Fabrice Desré]

We have a 5s penalty aat startup waiting for the batteryinfo service to come up:

02-24 18:23:39.430 E/AudioHardwareMSM76XXA( 2946): failed to open AUTO_VOLUME_CONTROL /system/etc/AutoVolumeControl.txt: No such file or directory (2)
02-24 18:23:39.470 I/AudioFlinger( 2946): AudioFlinger's thread 0xcc90 ready to run
02-24 18:23:39.470 W/AudioHardwareMSM76XXA( 2946): rpc_snd_set_device(6, 1, 1)
02-24 18:23:40.450 E/Sensors ( 2947): couldn't find 'gyro' input device
02-24 18:23:41.010 I/ServiceManager( 2947): Waiting for service batteryinfo...
02-24 18:23:42.010 I/ServiceManager( 2947): Waiting for service batteryinfo...
02-24 18:23:43.010 I/ServiceManager( 2947): Waiting for service batteryinfo...
02-24 18:23:44.010 I/ServiceManager( 2947): Waiting for service batteryinfo...
02-24 18:23:45.010 I/ServiceManager( 2947): Waiting for service batteryinfo...
02-24 18:23:46.050 I/EventHub( 2947): New keyboard: device->id=0x10000 devname='7k_handset' propName='hw.keyboards.65536.devname' keylayout='/system/usr/keylayout/qwerty.kl'
02-24 18:23:46.050 I/EventHub( 2947): New device: path=/dev/input/event6 name=7k_handset id=0x10000 (of 0x1) index=1 fd=34 classes=0x81
02-24 18:23:46.190 I/EventHub( 2947): New keyboard: device->id=0x40001 devname='7x27a_kp' propName='hw.keyboards.262145.devname' keylayout='/system/usr/keylayout/qwerty.kl'
02-24 18:23:46.190 I/EventHub( 2947): New device: path=/dev/input/event2 name=7x27a_kp id=0x40001 (of 0x2) index=2 fd=35 classes=0x1
02-24 18:23:46.210 I/EventHub( 2947): New keyboard: device->id=0x10002 devname='ft5x0x_ts' propName='hw.keyboards.65538.devname' keylayout='/system/usr/keylayout/qwerty.kl'
02-24 18:23:46.210 I/EventHub( 2947): New device: path=/dev/input/event1 name=ft5x0x_ts id=0x10002 (of 0x3) index=3 fd=36 classes=0x15
02-24 18:23:46.250 I/InputReader( 2947): Device reconfigured: id=0x10002, name=ft5x0x_ts, display size is now 0x0
02-24 18:23:46.250 I/Gonk    ( 2947): Device ft5x0x_ts has vbutton config '0x01:139:40:510:80:60:0x01:102:120:510:80:60:0x01:217:200:510:80:60:0x01:158:280:510:80:60

Comment 1

[[:fabrice] Fabrice Desré]

Attachment: patch

device.activate() was blocking during 5 seconds.

We're back to normal startup time with this patch.

Comment 2

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Comment on attachment 600672 [details] [diff] [review]
patch

>diff --git a/hal/gonk/GonkSensor.cpp b/hal/gonk/GonkSensor.cpp

>+typedef struct {

struct SensorInfo

>+      device.activate((void*)pthread_self(), sensors[i].handle, info->activate);

The identity here is used to key the sensor.  Here, it's a transient
pthread ID, which means we won't be able to look up the actual sensor
in SensorDevice.

>+static void
>+SensorSwitch(SensorType aSensor, bool activate)
>+{
>+  SensorInfo* info = (SensorInfo*)moz_malloc(sizeof(SensorInfo));
>+  if (!info)
>+    return;
>+  pthread_t thread;
>+  pthread_create(&thread, NULL, SensorSwitchRun, info);

Sensors can be switched on/off fairly frequently, and under control of
(privileged) content.  So I think spawning a pthread for each
enable/disable is going to be too expensive.  Keeping one around for
all enables/disables should be ok.

Also, when browsing back over GonkHal.cpp, I saw that my comments in
bug 714413 comment 15 weren't addressed (wrong patch attached?).  You
don't have to do that, but I'd appreciate it :).

Thanks for tackling this!

Comment 3

[[:fabrice] Fabrice Desré]

Attachment: patch v2

Addressing comments, except for the idea of reusing a single thread. Wouldn't this mean that we would queue sensor switch events and so may potentially still block some of them if we have a slow one in the queue?

Comment 4

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Comment on attachment 601141 [details] [diff] [review]
patch v2

(In reply to Fabrice Desré [:fabrice] from comment #3)
> Created attachment 601141 [details] [diff] [review]
> patch v2
> 
> Addressing comments, except for the idea of reusing a single thread.
> Wouldn't this mean that we would queue sensor switch events and so may
> potentially still block some of them if we have a slow one in the queue?

Yes, but the right way to deal with that is a thread pool.  pthread per request is not very palatable.

> static void
> SensorSwitch(SensorType aSensor, bool activate)
> {

>+      SensorInfo* info = (SensorInfo*)moz_malloc(sizeof(SensorInfo));

 = new SensorInfo();

it's infallible so no need to null-check.

Comment 5

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

(Sorry, this failed to send before I closed my laptop.)

(In reply to Chris Jones [:cjones] [:warhammer] from comment #4)
> Comment on attachment 601141 [details] [diff] [review]
> patch v2
> 
> (In reply to Fabrice Desré [:fabrice] from comment #3)
> > Created attachment 601141 [details] [diff] [review]
> > patch v2
> > 
> > Addressing comments, except for the idea of reusing a single thread.
> > Wouldn't this mean that we would queue sensor switch events and so may
> > potentially still block some of them if we have a slow one in the queue?
> 
> Yes, but the right way to deal with that is a thread pool.  pthread per
> request is not very palatable.
> 

To be clear, I don't think a thread pool is needed yet.  If we run into perf issues with one thread we can revisit.

Comment 6

[[:fabrice] Fabrice Desré]

Attachment: patch v3

Now using a single thead to dispatch sensor switch events.

Comment 7

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Comment on attachment 603448 [details] [diff] [review]
patch v3

>diff --git a/hal/gonk/GonkSensor.cpp b/hal/gonk/GonkSensor.cpp

>+    void Switch() {
>+     SensorDevice& device = SensorDevice::getInstance();
>+     device.activate((void*)threadId, sensor.handle, activate);

This is actually wrong ... we need to provide a per-sensor key.  But
this bug already existed, so please file a followup.

>+      // Post an event to the activation thread
>+      SensorInfo* info = 
>+      nsCOMPtr<nsIRunnable> event = NS_NewRunnableMethod(info, &SensorInfo::Switch);

Please rewrite this as 

 NS_NewRunnableMethod(new SensorInfo(activate, sensors[i], pthread_self()),
                      &SensorInfo::Switch);

or hold a ref to the SensorInfo object.  As it stands now |info| can
be a dangling pointer to freed memory after the Dispatch() call.

r=me with followup filed and that change.

Comment 8

[[:fabrice] Fabrice Desré]

https://hg.mozilla.org/integration/mozilla-inbound/rev/c2eec826a786

I filed bug 733615 as a followup

Comment 9

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/c2eec826a786