735726 - Maintenance service sometimes fails to start up, causing the updater to give up on it

Status: RESOLVED DUPLICATE of bug 766833

(Toolkit :: Application Update, defect)

Description

[Rain [:rain1] (inactive)]

This has happened twice in the last week: the maintenance service start up seems to have not happened or failed for some reason, causing a UAC prompt to be shown after a ~10 second delay. The delay leads to pretty bad UX.

Comment 1

[Brian R. Bondy [:bbondy]]

When this happens next could you go to services manager and see what the status of the maintenance service is? Does it say started or stopped or some other state?  I think we should add some logging into the service start code, if it fails to start it goes straight to the UAC prompt after waiting for the service to start.  I think for some reason your service is failing to start.

Comment 2

[Robert Strong (they/them - no direct email)]

Brian, I think the windows event log should provide some info here as well.

Comment 3

[Brian R. Bondy [:bbondy]]

Ya good idea, sid0 could you check for any service failed to start errors around when this problem happened in the Windows Event Log?

Comment 4

[Rain [:rain1] (inactive)]

I see a ton of errors of the form

The Mozilla Maintenance Service service failed to start due to the following error: 
The system cannot find the file specified.

spread across 6 seconds.

Here's one of the events in XML form:

- <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
- <System>
  <Provider Name="Service Control Manager" Guid="{555908d1-a6d7-4695-8e1e-26931d2012f4}" EventSourceName="Service Control Manager" /> 
  <EventID Qualifiers="49152">7000</EventID> 
  <Version>0</Version> 
  <Level>2</Level> 
  <Task>0</Task> 
  <Opcode>0</Opcode> 
  <Keywords>0x8080000000000000</Keywords> 
  <TimeCreated SystemTime="2012-03-14T07:11:31.313607600Z" /> 
  <EventRecordID>85957</EventRecordID> 
  <Correlation /> 
  <Execution ProcessID="712" ThreadID="852" /> 
  <Channel>System</Channel> 
  <Computer>Doukutsu</Computer> 
  <Security /> 
  </System>
- <EventData>
  <Data Name="param1">Mozilla Maintenance Service</Data> 
  <Data Name="param2">%%2</Data> 
  </EventData>
  </Event>

Comment 5

[Brian R. Bondy [:bbondy]]

That helps, thanks.

Comment 6

[Brian R. Bondy [:bbondy]]

The next time you see that this file doesn't exist (possibly now?):
C:\Program Files (x86)\Mozilla Maintenance Service\maintenanceservice.exe

Then please attach your install log. 
C:\ProgramData\Mozilla\logs\maintenanceservice-install.log

Comment 7

[Rain [:rain1] (inactive)]

Yeah, it doesn't exist right now.

The maintenance service install log is:

Upgrading service if installed...
User access was set successfully on the service.
The service description was updated successfully.
Sending stop request...
Waiting for service stop...
Done waiting for service stop, last service state: 1
The new service binary was copied in.
Deleting the old file path on the next reboot: C:\Program Files (x86)\Mozilla Maintenance Service\maintenanceservice_tmp.exe.
The service was upgraded successfully

and neither maintenanceservice nor maintenanceservice_tmp.exe exist right now (I've rebooted since then).

Comment 8

[Brian R. Bondy [:bbondy]]

So it's really strange that you got the message "The new service binary was copied in".  What is your service pointing to as its binary?  That's where it would be copied to.  Maybe somehow that path got changed from C:\Program Files (x86)\Mozilla Maintenance Service\maintenanceservice.exe.

In administrative tools, services, Mozilla Maintenance Service, properties, path to binary file.


From toolkit\components\maintenanceservice\serviceinstall.cpp:

> if (!CopyFileW(newServiceBinaryPath, 
>                serviceConfig.lpBinaryPathName, FALSE)) {
> ...
> } else {
>  LOG(("The new service binary was copied in.\n"));
> }

Comment 9

[Rain [:rain1] (inactive)]

(In reply to Brian R. Bondy [:bbondy] from comment #8)
> So it's really strange that you got the message "The new service binary was
> copied in".  What is your service pointing to as its binary?  That's where
> it would be copied to.  Maybe somehow that path got changed from C:\Program
> Files (x86)\Mozilla Maintenance Service\maintenanceservice.exe.
> 
> In administrative tools, services, Mozilla Maintenance Service, properties,
> path to binary file.

Hm, the path's correct.

Comment 10

[Brian R. Bondy [:bbondy]]

Could you check again after the next couple updates? I wonder if it fixed itself so next update will work again. But will inevitably fall back to the wrong path again eventually.  I'm thinking someone it is being set to the maintenanceservice_tmp.exe path

Comment 11

[Brian R. Bondy [:bbondy]]

Could you check the log over the next few days and keep an eye on this line:
Deleting the old file path on the next reboot: C:\Program Files (x86)\Mozilla Maintenance Service\maintenanceservice_tmp.exe.

In particular please see if it ever says maintenanceservice.exe instead of maintenanceservice_tmp.exe

Comment 12

[Rain [:rain1] (inactive)]

So seems like maintenanceservice.exe gets deleted at every reboot. HKLM\SYSTEM\CurrentControlSet\Control\Session Manager\PendingFileRenameOperations has both maintenanceservice.exe and maintenanceservice_tmp.exe marked to be deleted at next reboot.

Comment 13

[Rain [:rain1] (inactive)]

Aha, I think I know what the bug is:

1. After a reboot, neither maintenanceservice.exe nor maintenanceservice_tmp.exe are present.

2. The first time an update is installed, the newServiceBinaryPath is maintenanceservice.exe (I think).

3. At this point, since the service itself is present, schService is not null at <https://mxr.mozilla.org/mozilla-central/source/toolkit/components/maintenanceservice/serviceinstall.cpp#236>, so maintenanceservice.exe is always marked to be deleted at next reboot at <https://mxr.mozilla.org/mozilla-central/source/toolkit/components/maintenanceservice/serviceinstall.cpp#392>.

4. Go to 1.

So it seems like a good fix for this would be to only mark newServiceBinaryPath to be deleted if we've actually copied the file. That whole function's so complicated, though, that I'm not confident enough to write a correct patch.

Another good fix would be to always install the service from maintenanceservice_tmp.exe, regardless of whether maintenanceservice.exe is present or not.

One assumption that this code seems to be making is that if the service is present in the local services list, so is maintenanceservice.exe. That assumption is violated in my case.

Comment 14

[Brian R. Bondy [:bbondy]]

> One assumption that this code seems to be making is that if the service 
> is present in the local services list, so is maintenanceservice.exe. 
> That assumption is violated in my case.

I *think* you may have been stuck in this loop only because of Bug 716915.
This assumption I think is valid in all cases except in the case because of that bug.  I think I realized this in Bug 716915 Comment 6 previously.

Comment 15

[Rain [:rain1] (inactive)]

Yeah, though I think we should be resilient and not rely on it.

Comment 16

[Brian R. Bondy [:bbondy]]

Is this problem gone now? I think as per Comment 14 the problem would work itself out eventually.

Comment 17

[Rain [:rain1] (inactive)]

Well, the problem went away because I manually removed the delete at next reboot registry entries...

Comment 18

[Brian R. Bondy [:bbondy]]

Thanks sid0, this was fixed in bug 766833 if anyone else had this state and did not resolve it manually.