860355 - [B2G][System] OTA to Unagi v1.1 Mozilla RIL failed

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::System, defect)

Description

[Chris Kreinbring [:CKreinbring]]

Description:
A user that attempts to update their Firefox OS version via OTA will have their dvice rendered unusable.  Attempts to turn on the device will result in the company logo appearing for a few seconds before the screen goes black again.

Repro Steps:
1) Updated to Unagi Build ID: 20130409070205
2) Pull down the notification bar and select "# updates available".
3) Select Download and wait for the update to download.
4) Select Install Now once the download finishes.
5) Observe the device's appearance as the update is applied.

Actual:
The screen flashes and goes dark.  Nothing else happens with the device, although the buttons at the bottom of the device remain lit.  Holding down the power button for about 10 seconds will show the company logo for a few seconds before the screen goes dark again.

Expected:
The screen flashes and does dark.  About 20-30 seconds later, the Firefox OS logo appears and the device boots up with no errors.

Environmental Variables:
Kernel Date: Dec 5
Gecko: http://hg.mozilla.org/releases/mozilla-b2g18/rev/cfef36c0c8bc
Gaia: a80be95f553de517e5d8a159e04511cda5e38be4

Notes:
Repro frequency: 100%
Q Analysts Test Team Priority: Pri 1

Comment 1

[Chris Kreinbring [:CKreinbring]]

Attachment: Logs of OTA attempt

Comment 2

[Allen Maxwell]

This also fails on the Leo Mozilla build.

Comment 3

[Tony Chung [:tchung]]

(In reply to Allen Maxwell from comment #2)
> This also fails on the Leo Mozilla build.

This is likely bug 857632.   But lets keep this bug separate since the Unagi is affected.

Cc'ing' dave hylands and marshall from dev.   guys, can you help?

Comment 4

[Dave Hylands [:dhylands]]

So I'm not sure that this is an update problem. From the log:

04-10 10:01:38.000: I/GeckoUpdater(718): Finished applying update
04-10 10:01:38.570: I/GonkAutoMounter(718): Mounted /system partition as read-only
...
04-10 10:01:38.741: I/Gecko(523): UpdatePrompt: Update is ready to apply, registering idle timeout of 600 seconds before prompting.
...
04-10 10:01:45.107: I/Gecko(523): UpdatePrompt: Update downloaded, restarting to apply it
...
b2g restarts
...
04-10 10:01:47.910: I/GonkAutoMounter(727): Mounted /system partition as read-write
04-10 10:01:48.010: I/GeckoUpdater(727): Finished applying update
04-10 10:01:48.290: I/GonkAutoMounter(727): Mounted /system partition as read-only

and then this seems to be the real problem:

04-10 10:01:54.776: I/Gecko(740): SettingsService failed to open DB!
04-10 10:01:54.786: I/Gecko(740): SettingsService failed to open DB!
04-10 10:01:54.796: I/Gecko(740): SettingsService failed to open DB!
04-10 10:01:54.806: I/Gecko(740): SettingsService failed to open DB!
04-10 10:01:54.806: I/Gecko(740): SettingsService failed to open DB!
04-10 10:01:54.816: I/Gecko(740): Cannot open Settings DB. Trying to open an old version?
04-10 10:01:54.816: I/Gecko(740): Cannot open Settings DB. Trying to open an old version?
04-10 10:01:54.826: I/Gecko(740): Cannot open Settings DB. Trying to open an old version?
04-10 10:01:54.826: I/Gecko(740): Cannot open Settings DB. Trying to open an old version?

I added gwagner and bent, since they seem to be working on something related to databases moving?

Comment 5

[Chris Kreinbring [:CKreinbring]]

At Tony Chung's request, I attempted to perform an adb reboot on an afflicted device.  I also pulled the battery and attempted to restart the device after putting the battery back in.  Unfortunately, the device reacted the same way as the actual results in both tests.

Comment 6

[Ben Turner (not reading bugmail, use the needinfo flag!)]

This was caused by the fact that bug 857376 was in briefly and then got backed out. When bug 857376 landed all databases were upgraded to a newer version. Once bug 857376 was backed out gecko no longer knows how to open those databases.

Comment 7

[Tony Chung [:tchung]]

this blocks internal testing on OTA.  flagging for blocking-b2g

Comment 8

[Chris Kreinbring [:CKreinbring]]

Attachment: Logs of OTA attempt from 4/9 to 4/11

An attempt to OTA from 2013041070209 to 20130411070205 on the Unagi went fine.  The device installed the update and restarted with no errors.

An attempt to OTA from 20130409070205 to 20130411070205 on the Unagi resulted in the bug reproducing.

I'm attaching a log of the latter attempt.

Comment 9

[Tony Chung [:tchung]]

when bug 857376 is fixed, this bug can be reverified OTA.   (use a April 9th build to do the OTA test tomorrow)

Comment 10

[Tracy Walker [:tracy]]

OTA'd with unagi device from 20130407070205 to 4/12 build.  Device is rendered useless.  I can hold the power button to get the airplane mode/shutdown menu. 

Powering off, then turning the device back on resolves the issue.  New bug?

Comment 11

[Dave Hylands [:dhylands]]

(In reply to Tracy Walker [:tracy] from comment #10)
> OTA'd with unagi device from 20130407070205 to 4/12 build.  Device is
> rendered useless.  I can hold the power button to get the airplane
> mode/shutdown menu. 
> 
> Powering off, then turning the device back on resolves the issue.  New bug?

Perhaps. Having the logcat would be useful.

Comment 12

[Tracy Walker [:tracy]]

Was logging the session but also doing some related email checks. anyway, log buffer too small and this portion is gone.  I'll have to start all over to repro for logs, but will get it for you.

Comment 13

[Tracy Walker [:tracy]]

Attachment: Log of failed restart after OTA update

Comment 14

[Dave Hylands [:dhylands]]

(In reply to Tracy Walker [:tracy] from comment #13)
> Created attachment 736871 [details]
> Log of failed restart after OTA update

The log seems incomplete. It ends with:

04-12 12:45:13.961: I/Gecko(109): *** AUS:SVC Downloader:onProgress - progress: 13312633/50351714
04-12 12:45:14.532: I/Gecko(109): *** AUS:SVC

Comment 15

[Tracy Walker [:tracy]]

Attachment: Fail to restart after applying update

sorry about that.  this one is correct.

Every couple minutes or so, it cycles through those last three lines

Comment 16

[Dave Hylands [:dhylands]]

So I see this message:

04-12 13:50:01.010: I/Gecko(550): *** AUS:SVC UpdateManager:get activeUpdate - channel has changed, reloading default preferences to workaround bug 802022
04-12 13:50:01.010: E/GeckoConsole(550): AUS:SVC UpdateManager:get activeUpdate - channel has changed, reloading default preferences to workaround bug 802022

So I think that you're running into bug 841962 which is really bug 842932

The fix for that was minused for uplift, so the only solution for right now is to reboot the phone.

Comment 17

[Tracy Walker [:tracy]]

ok. my changing from leo- to leo? was an accident that I just noticed. 

How do we want this resolved?

Comment 18

[Tony Chung [:tchung]]

(In reply to Tracy Walker [:tracy] from comment #17)
> ok. my changing from leo- to leo? was an accident that I just noticed. 
> 
> How do we want this resolved?

I'll try and push for bug 842932 to get uplifted to tef+.   OTA testing into a dark screen is a regression on unagi and a smoketest blocker for QA.

Triage please consider this for leo+ for now.  if i can get 842932 to tef+, i'll switch this one too.

Comment 19

[Tracy Walker [:tracy]]

I think what I have run into is bug 847511

Comment 20

[Dave Hylands [:dhylands]]

(In reply to Tracy Walker [:tracy] from comment #19)
> I think what I have run into is bug 847511

That's really the same as bug 842932

It's already fixed on master. I guess you could nom it again, and see if they'll allow the fix to be uplifted.

Comment 21

[Tony Chung [:tchung]]

removing Leo from this bug.  The Leo whitescreen issue is for 1.1, and tracked in bug 857633.

Comment 22

[Alex Keybl [:akeybl]]

Bug 842932 is tef+ and bug 857633 is leo+

Comment 23

[Tony Chung [:tchung]]

Tracy or Chris Kreinbring, can you guys retest this bug on latest 1.0.1 and see if it works for the Unagi?   bug 860355 was fixed and landed on 1.0.1 train 16 hours ago.

Thanks.

Comment 24

[Tracy Walker [:tracy]]

1.0.1 builds do not finish the update process correctly. Doing an OTA puts the device in an unusable state. The device has to be manually flashed to the latest build.  tested with 0414-0415 builds

Comment 25

[Tracy Walker [:tracy]]

ah, I just noticed the 16 hours ago comment.  I'll find the latest build prior to the fixed one and retest.  sorry.

Comment 26

[Tracy Walker [:tracy]]

updating from 20130415070205 fails.

updating from 20130415230205 fails with:

04-16 09:15:54.113: I/Gecko(588): Cannot open Settings DB. Trying to open an old version?
04-16 09:15:54.113: I/Gecko(588): SettingsService failed to open DB!
04-16 09:15:54.123: I/Gecko(588): Cannot open Settings DB. Trying to open an old version?
04-16 09:15:54.133: I/Gecko(588): Cannot open Settings DB. Trying to open an old version?
04-16 09:15:54.133: I/Gecko(588): Cannot open Settings DB. Trying to open an old version?
04-16 09:15:54.143: I/Gecko(588): Cannot open Settings DB. Trying to open an old version?

04-16 09:15:54.143: I/Gecko(588): Cannot open Settings DB. Trying to open an old version?
04-16 09:15:54.153: I/Gecko(588): SettingsService failed to open DB!
04-16 09:15:59.328: E/profiler(639): Registering start signal
04-16 09:15:59.918: I/Gecko(639): ###################################### forms.js loaded
04-16 09:15:59.938: I/Gecko(639): ############################### browserElementPanning.js loaded
04-16 09:15:59.998: I/Gecko(639): ######################## BrowserElementChildPreload.js loaded

then: 

04-16 09:17:23.850: E/rmt_storage(132): write_log_file: [MyTag]open: fd=-1
04-16 09:17:23.850: E/rmt_storage(132): block rmt_storage client thread
04-16 09:18:09.515: I/wpa_supplicant(377): CTRL_IFACE monitor[0]: 111 - Connection refused
04-16 09:18:09.525: I/wpa_supplicant(377): wlan0: WPA: Group rekeying completed with 00:0f:b5:64:b2:24 [GTK=TKIP]
04-16 09:18:09.525: I/wpa_supplicant(377): CTRL_IFACE monitor[0]: 111 - Connection refused
04-16 09:18:09.525: I/wpa_supplicant(377): CTRL_IFACE monitor[0]: 111 - Connection refused

reboot does not work. I can't manually flash a build either. The device is hosed.

Comment 27

[Tracy Walker [:tracy]]

my builds in previous comments today were 1.1 builds. (still trying to understand this build naming convention).

I finally found the 1.0.1 nightly builds.  updating from yesterday evenings (nightly channel) build to today's build updates the device to 1.1 (beta channel). so something is hosed in the update system

Comment 28

[Chris AtLee [:catlee]]

(In reply to Tracy Walker [:tracy] from comment #27)
> my builds in previous comments today were 1.1 builds. (still trying to
> understand this build naming convention).
> 
> I finally found the 1.0.1 nightly builds.  updating from yesterday evenings
> (nightly channel) build to today's build updates the device to 1.1 (beta
> channel). so something is hosed in the update system

That will be fixed by bug 861426

Comment 29

[Allen Maxwell]

The primary issue, OTA to Unagi v1.1 Mozilla RIL, is no longer reproducible.

Build ID: 20130422070204
Kernel Date: Dec 5
Gecko: http://hg.mozilla.org/releases/mozilla-b2g18/rev/dfa6bdc5e6da
Gaia: 3cdab45a783efadf9b97decf46bd15b83fb91ed8

Comment 30

[Allen Maxwell]

When trying to OTA from Unagi v1.1 Mozilla RIL Build 20130506070204 to 2013201305070204, device will download and install 20130506105248 with no further updates available.

Build ID: 20130506070204
Gecko: http://hg.mozilla.org/releases/mozilla-b2g18/rev/00c554abfc17
Gaia: 9377636cee5ac55b9f1d68f598afc7aadfbb2b00

Request escalation to P1 due to this build is for dogfooders who need OTA capability.

Comment 31

[Chris AtLee [:catlee]]

Can you verify if this works now?

Comment 32

[Tony Chung [:tchung]]

This is verified working now.   multiple QA folks have tested updating from unagi 1.1 builds to latest build via OTA>

Comment 33

[John Ford [:jhford] CET/CEST Berlin Time]

is this resolved on branch? If so, can we mark it like that?

Comment 34

[John Ford [:jhford] CET/CEST Berlin Time]

I'm adding this bug to the list of bugs that I skip during uplifts.  Please email me directly if there is action that I need to take.

Comment 35

[Chris Kreinbring [:CKreinbring]]

Verified no longer occurs on Unagi 1.1 mozilla RIL.

Build ID: 20130730070228
Gecko: http://hg.mozilla.org/releases/mozilla-b2g18/rev/1fe3339e3d96
Gaia: 6221737cb50d6e8435ac5d3fe3b7e2788bd8a37c
Platform Version: 18.1