1023470 - Fine Grained Network online event for the different network types.

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: RIL, defect)

Description

[:gerard-majax]

While sending a MMS I was surprised to get the « An error occurred while checking for updates » toaster.

Having a look at logcat shows that while the rmnet interface was brought up for the sole purpose of sending the MMS, there was an online network event that got triggered, and this made apps trying to make use of the network. I feel it's bad because:
 - content should not be notified of a network it is not supposed to use
 - this may trigger data use that the user did not wanted
 - it will slow down the MMS sending itself

Following is the logcatoutput showing the event being propagated to the apps. Please not that neither WiFi nor data are enabled.

06-10 20:39:56.070    82   878 I CameraHardwareSec: int android::CameraHardwareSec::previewThreadWrapper(): calling mSecCamera->stopPreview() and waiting
06-10 20:39:56.132    82    82 I CameraHardwareSec: void android::CameraHardwareSec::stopPreviewInternal() : preview not running, doing nothing
06-10 20:39:56.132    82   125 I CameraHardwareSec: void android::CameraHardwareSec::stopPreviewInternal() : preview not running, doing nothing
06-10 20:39:56.132    82   878 I CameraHardwareSec: int android::CameraHardwareSec::previewThreadWrapper(): return from wait
06-10 20:39:56.132    82   878 I CameraHardwareSec: int android::CameraHardwareSec::previewThreadWrapper(): exiting
06-10 20:39:56.132    82   878 W SecCamera: int android::SecCamera::stopPreview(): doing nothing because m_flag_camera_start is zero
06-10 20:39:56.132    82   125 W SecCamera: int android::SecCamera::stopRecord(): doing nothing because m_flag_record_start is zero
06-10 20:39:56.132    82   125 I SecCamera: DeinitCamera: m_cam_fd(17)
06-10 20:39:56.136    82   125 I SecCamera: DeinitCamera: m_cam_fd2(18)
06-10 20:39:56.144    82   125 E CameraHardwareSec: preview window is NULL!
06-10 20:39:56.144    82   125 I CameraService: Destroying camera 0
06-10 20:39:56.144    82   125 I CameraHardwareSec: int android::HAL_camera_device_close(hw_device_t*)
06-10 20:39:56.144    82   125 I SecCamera: DeinitCamera : already deinitialized
06-10 20:39:56.148    82    82 W AudioFlinger: session id 2 not found for pid 82
06-10 20:39:56.148    82    82 W AudioFlinger: session id 3 not found for pid 82
06-10 20:39:56.160   764   764 I Gecko   : 
06-10 20:39:56.160   764   764 I Gecko   : ###!!! [Child][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
06-10 20:39:56.160   764   764 I Gecko   : 
06-10 20:39:56.222    76   128 I Gecko   : [Parent 76] WARNING: pipe error (172): Connection reset by peer: file /home/alex/codaz/B2G/gecko/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 450
06-10 20:39:56.222    76   128 I Gecko   : [Parent 76] WARNING: pipe error (176): Connection reset by peer: file /home/alex/codaz/B2G/gecko/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 450
06-10 20:39:56.226    76   128 I Gecko   : [Parent 76] WARNING: pipe error (258): Connection reset by peer: file /home/alex/codaz/B2G/gecko/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 450
06-10 20:40:00.543    76    76 I Gonk    : Setting nice for pid 218 to 1
06-10 20:40:00.543    76    76 I Gonk    : Changed nice for pid 218 from 18 to 1.
06-10 20:40:05.312   745   778 I Gecko   : WLOG: Email knows that it is: online and previously was: offline
06-10 20:40:05.312   745   778 I Gecko   : WLOG: runOp(do: {"type":"syncFolderList","longtermId":"I/C","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"syncFolderList"})
06-10 20:40:05.328    76    76 I Gecko   : *** AUS:SVC UpdateService:_offlineStatusChanged - network is online, forcing another background check
06-10 20:40:05.332    76    76 E GeckoConsole: AUS:SVC UpdateService:_offlineStatusChanged - network is online, forcing another background check
06-10 20:40:05.332    76    76 I Gecko   : *** AUS:SVC UpdateService:_attemptResume
06-10 20:40:05.332    76    76 E GeckoConsole: AUS:SVC UpdateService:_attemptResume
06-10 20:40:05.332    76    76 I Gecko   : *** AUS:SVC Checker: checkForUpdates, force: false
06-10 20:40:05.332    76    76 E GeckoConsole: AUS:SVC Checker: checkForUpdates, force: false
06-10 20:40:05.355    76    76 I Gecko   : *** AUS:SVC Checker:getUpdateURL - update URL: http://localhost/update.xml
06-10 20:40:05.355    76    76 E GeckoConsole: AUS:SVC Checker:getUpdateURL - update URL: http://localhost/update.xml
06-10 20:40:05.367    76    76 I Gecko   : *** AUS:SVC Checker:checkForUpdates - sending request to: http://localhost/update.xml
06-10 20:40:05.367    76    76 E GeckoConsole: AUS:SVC Checker:checkForUpdates - sending request to: http://localhost/update.xml
06-10 20:40:05.871    76    76 I Gecko   : *** AUS:SVC Checker:onError - request.status: 2152398861
06-10 20:40:05.871    76    76 E GeckoConsole: AUS:SVC Checker:onError - request.status: 2152398861
06-10 20:40:05.871    76    76 I Gecko   : *** AUS:SVC getStatusTextFromCode - transfer error: Connection refused, code: 2152398861
06-10 20:40:05.871    76    76 E GeckoConsole: AUS:SVC getStatusTextFromCode - transfer error: Connection refused, code: 2152398861
06-10 20:40:05.886    76    76 I Gecko   : *** AUS:SVC UpdateService:onError - error during background update. error code: 2152398861, status text: Connection refused
06-10 20:40:05.886    76    76 E GeckoConsole: AUS:SVC UpdateService:onError - error during background update. error code: 2152398861, status text: Connection refused
06-10 20:40:05.890    76    76 I Gecko   : UpdatePrompt: Update error, state: , errorCode: 110
06-10 20:40:05.945    76    76 E GeckoConsole: [JavaScript Error: "formatURLPref: Couldn't get pref: app.update.url.details" {file: "jar:file:///system/b2g/omni.ja!/components/nsURLFormatter.js" line: 134}]
06-10 20:40:05.953    76    76 I Gecko   : UpdatePrompt: Warning: no patches available in update
06-10 20:40:05.953    76    76 I Gecko   : UpdatePrompt: Setting gecko.updateStatus: Connection refused
06-10 20:40:07.672   745   778 I Gecko   : WERR: Connect error: unresponsive-server formal: Error: Unable to connect. Reason: [object Object] on XX 143
06-10 20:40:08.136   265   265 E GeckoConsole: Content JS ERROR at app://verticalhome.gaiamobile.org/shared/elements/gaia_grid/js/icon_retriever.js:86 in doGet/xhr.ontimeout: Error while HTTP GET:  http://k5e.github.io/spclock/app/assets/icon-256.png
06-10 20:40:08.683   265   265 E GeckoConsole: Content JS ERROR at app://verticalhome.gaiamobile.org/shared/elements/gaia_grid/js/icon_retriever.js:86 in doGet/xhr.ontimeout: Error while HTTP GET:  http://mozilla.clock6.com/128.png
06-10 20:40:13.015    76    76 I Gonk    : Setting nice for pid 252 to 1
06-10 20:40:13.015    76    76 I Gonk    : Changed nice for pid 252 from 18 to 1.
06-10 20:40:13.078   745   778 I Gecko   : WERR: Connect error: unresponsive-server formal: Error: Unable to connect. Reason: [object Object] on XX 143
06-10 20:40:13.332   252   252 I Gecko   : ###################################### forms.js loaded
06-10 20:40:13.390   252   252 I Gecko   : ############################### browserElementPanning.js loaded
06-10 20:40:13.504   252   252 I Gecko   : ######################## BrowserElementChildPreload.js loaded
06-10 20:40:16.090   252   252 E GeckoConsole: Content JS WARN at app://costcontrol.gaiamobile.org/gaia_build_message_handler.js:262 in _requestService: SimManager is not ready, waiting for initialized custom event
06-10 20:40:16.660    76    76 I Gonk    : Setting nice for pid 252 to 7
06-10 20:40:16.660    76    76 I Gonk    : Changed nice for pid 252 from 1 to 7.
06-10 20:40:18.507   745   778 I Gecko   : WERR: Connect error: unresponsive-server formal: Error: Unable to connect. Reason: [object Object] on XX 143
06-10 20:40:22.187    76    76 I Gonk    : Setting nice for pid 252 to 18
06-10 20:40:22.187    76    76 I Gonk    : Changed nice for pid 252 from 7 to 18.
06-10 20:40:29.636    76    76 I Gonk    : Setting nice for pid 252 to 18
06-10 20:40:29.636    76    76 I Gonk    : Changed nice for pid 252 from 18 to 18.
06-10 20:40:29.636    76    76 I Gonk    : Setting nice for pid 417 to 18
06-10 20:40:29.636    76    76 I Gonk    : Changed nice for pid 417 from 1 to 18.
06-10 20:40:29.656    76    76 I power   : *** set_screen_state 0

Comment 1

[Bevis Tseng[:bevis][:btseng](Exited)]

It is not possible to know type of the connection by only observing 'network:offline-status-changed' when multiple types of connections are available in the mobile device.
In current design among NetworkManager(Gonk only), DNSService(Gecko) and Service.io(Gecko):
1. DNSService is controlled by toggling Service.io.offline.
2. 'network:offline-status-changed' is triggered by the change of Service.io.offline.
3. In NetworkManager, after a connection(internet, mms, supl, etc) is established, we have to set Service.io.offline to false to enable the DNS to resolve the hosts in the APN settings to ensure the routing of the host is correct.

Hence, it's not sufficient for AUS (Application Update Service) and other apps to only listen to the topic of 'network:offline-status-changed' triggered by the change of Service.io.offline without being aware of the connection type when they would like to access the internet.

For this bug, since AUS is running inside gecko, instead of listening to 'network:offline-status-changed', AUS can check the type and the state of the connection before starting the update by 
1. listening to 'network-connection-state-changed' fired by NetworkManager. [1]
2. Check the connection state (NETWORK_STATE_CONNECTED) & network type(NETWORK_TYPE_WIFI or NETWORK_TYPE_MOBILE) of the NetworkInterface. [2]

[1] http://dxr.mozilla.org/mozilla-central/source/dom/system/gonk/NetworkManager.js#43
[2] http://dxr.mozilla.org/mozilla-central/source/dom/system/gonk/nsINetworkManager.idl

Comment 2

[Julien Wajsberg [:julienw]]

Bevis, do you know who can be in charge for this issue?

Comment 3

[Bevis Tseng[:bevis][:btseng](Exited)]

(In reply to Julien Wajsberg [:julienw] from comment #2)
> Bevis, do you know who can be in charge for this issue?

I also have the same question. :(

For the "offline" definition in gecko, I think we need someone more familiar with the entire gecko design to re-think and see how to expand the offline/online scenario when taking mobile platform into consideration, because the online/offline info in IOService is not sufficient to represent the state of multiple connections available in mobile device.

I am not pretty sure if there is any possibility in the future that some applications in gaia will need to the access of specific mobile connection, for example, like IMS. IMS connection provides the access to IMS related services(VoIP, IM, Presence) from carrier, and unlike MMS connection(established when needed), IMS connection is more likely to be a persistent connection because all the CS related services(Call, Messaging) are move to PS network. Then, the same problem happens if there is no mobile internet/wifi but IMS. Shall device be treated as offline?

Comment 4

[Bevis Tseng[:bevis][:btseng](Exited)]

If we only concern the symptom of AUS in comment 0 for short-term solution, then AUS owner can follow the suggestion in comment 1 to fix it.

Comment 5

[:gerard-majax]

Can't we just avoid sending the online event notification when we are setting up a MMS APN?

Comment 6

[Bevis Tseng[:bevis][:btseng](Exited)]

(In reply to Alexandre LISSY :gerard-majax from comment #5)
> Can't we just avoid sending the online event notification when we are
> setting up a MMS APN?

No, as mentioned in comment 1, the DNSService has to be enabled by toggling IOService.offline and the online/offline event was sent by IOService.
If we don't have DNSService, in this case, we are not able to send MMS. :(

Comment 7

[:gerard-majax]

(In reply to Bevis Tseng [:bevistseng] ([e-mail]) from comment #6)
> (In reply to Alexandre LISSY :gerard-majax from comment #5)
> > Can't we just avoid sending the online event notification when we are
> > setting up a MMS APN?
> 
> No, as mentioned in comment 1, the DNSService has to be enabled by toggling
> IOService.offline and the online/offline event was sent by IOService.
> If we don't have DNSService, in this case, we are not able to send MMS. :(

Then we need to fix this. Discovering this behavior, I now understand a lot better why I may have such a hard time sending MMS and why it fails so many times ...

Comment 8

[Bevis Tseng[:bevis][:btseng](Exited)]

(In reply to Alexandre LISSY :gerard-majax from comment #7)
> (In reply to Bevis Tseng [:bevistseng] ([e-mail]) from comment #6)
> > (In reply to Alexandre LISSY :gerard-majax from comment #5)
> > > Can't we just avoid sending the online event notification when we are
> > > setting up a MMS APN?
> > 
> > No, as mentioned in comment 1, the DNSService has to be enabled by toggling
> > IOService.offline and the online/offline event was sent by IOService.
> > If we don't have DNSService, in this case, we are not able to send MMS. :(
> 
> Then we need to fix this. Discovering this behavior, I now understand a lot
> better why I may have such a hard time sending MMS and why it fails so many
> times ...

That sounds wierd. 

From the log and current implmentation, it shall only cause the failure of the update request from AUS or the internet access from other apps because MMS connection might not have the access to the internet unless shared APN to internet APN is applied for some carrier.
MMS shall be sent correctly without being interfered by other transactions.

Comment 9

[:gerard-majax]

(In reply to Bevis Tseng [:bevistseng] ([e-mail]) from comment #8)
> (In reply to Alexandre LISSY :gerard-majax from comment #7)
> > (In reply to Bevis Tseng [:bevistseng] ([e-mail]) from comment #6)
> > > (In reply to Alexandre LISSY :gerard-majax from comment #5)
> > > > Can't we just avoid sending the online event notification when we are
> > > > setting up a MMS APN?
> > > 
> > > No, as mentioned in comment 1, the DNSService has to be enabled by toggling
> > > IOService.offline and the online/offline event was sent by IOService.
> > > If we don't have DNSService, in this case, we are not able to send MMS. :(
> > 
> > Then we need to fix this. Discovering this behavior, I now understand a lot
> > better why I may have such a hard time sending MMS and why it fails so many
> > times ...
> 
> That sounds wierd. 
> 
> From the log and current implmentation, it shall only cause the failure of
> the update request from AUS or the internet access from other apps because
> MMS connection might not have the access to the internet unless shared APN
> to internet APN is applied for some carrier.
> MMS shall be sent correctly without being interfered by other transactions.

Consider sending MMS when network conditions are not good. You have quite a lot of apps installed. Upon connection of the MMS APN, you have not only the Gecko update service that does network requests, but also all other apps.

In bad network conditions, this will slow down sending MMS, eventually to a point where it will fail. I'm experiencing it quite often, when in high speed train for example.

Comment 10

[Bevis Tseng[:bevis][:btseng](Exited)]

(In reply to Alexandre LISSY :gerard-majax from comment #9)
>
> In bad network conditions, this will slow down sending MMS, eventually to a
> point where it will fail. I'm experiencing it quite often, when in high
> speed train for example.
This shall be related to the bad network condition instead. :(

Comment 11

[:gerard-majax]

(In reply to Bevis Tseng [:bevistseng] ([e-mail]) from comment #10)
> (In reply to Alexandre LISSY :gerard-majax from comment #9)
> >
> > In bad network conditions, this will slow down sending MMS, eventually to a
> > point where it will fail. I'm experiencing it quite often, when in high
> > speed train for example.
> This shall be related to the bad network condition instead. :(

No, you are missing the point there: the fact that we are doing a lot of un-needed network requests makes the bad network condition a bigger issue. Even if packets are getting rejected by the network because they are not for the MMSC, we still have to send them over the air, hence using bandwidth for nothing.

Comment 12

[Bevis Tseng[:bevis][:btseng](Exited)]

(In reply to Alexandre LISSY :gerard-majax from comment #11)
> No, you are missing the point there: the fact that we are doing a lot of
> un-needed network requests makes the bad network condition a bigger issue.
> Even if packets are getting rejected by the network because they are not for
> the MMSC, we still have to send them over the air, hence using bandwidth for
> nothing.

No, actually, in this case, there is no default route when MMS connection is applied. [1]
That's means unless the traffics are toward to MMSC address, 
other traffics are blocked locally and will not be sent to the network side.

[1] http://dxr.mozilla.org/mozilla-central/source/dom/system/gonk/NetworkManager.js#613

Comment 13

[:gerard-majax]

(In reply to Bevis Tseng [:bevistseng] ([e-mail]) from comment #12)
> (In reply to Alexandre LISSY :gerard-majax from comment #11)
> > No, you are missing the point there: the fact that we are doing a lot of
> > un-needed network requests makes the bad network condition a bigger issue.
> > Even if packets are getting rejected by the network because they are not for
> > the MMSC, we still have to send them over the air, hence using bandwidth for
> > nothing.
> 
> No, actually, in this case, there is no default route when MMS connection is
> applied. [1]
> That's means unless the traffics are toward to MMSC address, 
> other traffics are blocked locally and will not be sent to the network side.
> 
> [1]
> http://dxr.mozilla.org/mozilla-central/source/dom/system/gonk/NetworkManager.
> js#613

I know, I wrote some early version of this. Thing is, my logs shows we are doing requests. See also the errors from the email client: it says it's unresponsive.

Comment 14

[Bevis Tseng[:bevis][:btseng](Exited)]

(In reply to Alexandre LISSY :gerard-majax from comment #13)
> I know, I wrote some early version of this. Thing is, my logs shows we are
> doing requests. See also the errors from the email client: it says it's
> unresponsive.

Well, I see your point.

The concern shall be that there might be some annoying error popping up to 
the user such as the error message from AUS mentioned in comment 0.

Then, we need someone's help to see how can we unbundle the need of DNSService and
related network modules in gecko without toggling IOService.offline for non-internet network access. :(

Comment 15

[bhavana bajaj [:bajaj]]

Are you able to repro this consistently with some specific STR?

Comment 16

[Jason Smith [:jsmith]]

Gregor - Can you ping Alexandre to get a response here?

Comment 17

[:gerard-majax]

(In reply to bhavana bajaj [:bajaj] from comment #15)
> Are you able to repro this consistently with some specific STR?

What is not clear about sending MMS ? I haven't had time to perform tcpdump to cross check.

Comment 18

[bhavana bajaj [:bajaj]]

(In reply to Alexandre LISSY :gerard-majax from comment #17)
> (In reply to bhavana bajaj [:bajaj] from comment #15)
> > Are you able to repro this consistently with some specific STR?
> 
> What is not clear about sending MMS ? I haven't had time to perform tcpdump
> to cross check.

I don't think QA is able to repro this in their daily testing, hence my questions. Let me add qawanted to see if they can reproduce this by "just sending an MMS" as you state!

Comment 19

[:gerard-majax]

(In reply to bhavana bajaj [:bajaj] [NOT reading Bugmail, needInfo please] from comment #18)
> (In reply to Alexandre LISSY :gerard-majax from comment #17)
> > (In reply to bhavana bajaj [:bajaj] from comment #15)
> > > Are you able to repro this consistently with some specific STR?
> > 
> > What is not clear about sending MMS ? I haven't had time to perform tcpdump
> > to cross check.
> 
> I don't think QA is able to repro this in their daily testing, hence my
> questions. Let me add qawanted to see if they can reproduce this by "just
> sending an MMS" as you state!

And I'm sorry but I don't know what QA can/cannot do. So I checked with tcpdump on my Flame, and it turns out that I do see some DNS resolution being made, but nothing more.

Here are my STR:
 0. Make sure no WiFi nor data is connected
 1. Prepare the Settings app to be ready to tap "Check now"
 2. Start capturing network packets: |tcpdump -i any -w /storage/sdcard/mms.pcap -s0| (bug 1025788)

Expected:
 No request being made to network.

Actual:
 I do see some DNS resolution.

I haven't seen more than DNS resolution so far. So it may not be that blocking.

Comment 20

[Lionel Mauritson]

(In reply to bhavana bajaj [:bajaj] [NOT reading Bugmail, needInfo please] from comment #18)
> (In reply to Alexandre LISSY :gerard-majax from comment #17)
> > (In reply to bhavana bajaj [:bajaj] from comment #15)
> > > Are you able to repro this consistently with some specific STR?
> > 
> > What is not clear about sending MMS ? I haven't had time to perform tcpdump
> > to cross check.
> 
> I don't think QA is able to repro this in their daily testing, hence my
> questions. Let me add qawanted to see if they can reproduce this by "just
> sending an MMS" as you state!


When sending an MMS I don't get any messages about checking for updates, or any other error that would be obvious to the user.

Is this a simple notification or should I be looking for this elsewhere?

Comment 21

[:gerard-majax]

(In reply to Lionel Mauritson from comment #20)
> (In reply to bhavana bajaj [:bajaj] [NOT reading Bugmail, needInfo please]
> from comment #18)
> > (In reply to Alexandre LISSY :gerard-majax from comment #17)
> > > (In reply to bhavana bajaj [:bajaj] from comment #15)
> > > > Are you able to repro this consistently with some specific STR?
> > > 
> > > What is not clear about sending MMS ? I haven't had time to perform tcpdump
> > > to cross check.
> > 
> > I don't think QA is able to repro this in their daily testing, hence my
> > questions. Let me add qawanted to see if they can reproduce this by "just
> > sending an MMS" as you state!
> 
> 
> When sending an MMS I don't get any messages about checking for updates, or
> any other error that would be obvious to the user.
> 
> Is this a simple notification or should I be looking for this elsewhere?

As documented in the previous comment, using tcpdump shows there is only DNS resolution performed. My device has an updateURL targetting localhost, that explains the update toaster.

Comment 22

[Julien Wajsberg [:julienw]]

Alexandre, do you think this bug could happen to an end-user ?

I don't really follow everything :)

Comment 23

[:gerard-majax]

(In reply to Julien Wajsberg [:julienw] (away June 21 to 30) from comment #22)
> Alexandre, do you think this bug could happen to an end-user ?
> 
> I don't really follow everything :)

Yes, sorry. So clearly, the current behavior is bad, but after careful checking and tcpdumping, there should have no impact for real users. Sorry for this noise.

Comment 24

[:gerard-majax]

Any news ?

Comment 25

[Bevis Tseng[:bevis][:btseng](Exited)]

I'd like to suggest to put this as part of NetworkManager enhancement.

Comment 26

[:gerard-majax]

(In reply to Bevis Tseng[:bevistseng][:btseng] from comment #25)
> I'd like to suggest to put this as part of NetworkManager enhancement.

Any news ?

Comment 27

[Bevis Tseng[:bevis][:btseng](Exited)]

+jjong

The NetworkManager is kept improving we should take this bug into consideration as well.

Comment 28

[Jessica Jong [:jessica] (inactive)]

As Bevis pointed out in comment 1 and comment 3, NetworkManager needs to toggle the Services.io.offline flag for DNS service to work, however Services.io.offline may not be the best option for mobile platforms, since in a mobile platform, there may be multiple connections and some of them may not have a default route. This is a topic we need to discuss with Necko team to see what can be done. We can bring up this to them during the Orlando work week.

A similar issue can also be found at bug 967792, which solves the "localhost" case.
For other cases, a solution on B2G is: modules running in gecko should listen to "network-active-changed" event, which is fired whenever there is a change on default connections.
After NetworkManager enhancement, we'll also have an webapi for this for web apps.

Comment 29

[BMO Automation]

Firefox OS is not being worked on