Re: D-Bus Timeouts

2013-05-15 Thread Daniel Wagner

Hi,

On 01/14/2013 02:20 PM, Daniel Wagner wrote:

On 14.01.2013 14:08, Daniel Wagner wrote:

when something blocks:

connmanMonitor::servicesChanged
START: getServices !
getServices duration: 0.00296497344971
START: getServices !
getServices duration: 0.00302910804749
START: getServices !
getServices duration: 0.00310301780701
connmanMonitor::managerPropertyChanged
connmanMonitor::propertyChanged
connmanMonitor::managerPropertyChanged
connmanMonitor::propertyChanged
connmanMonitor::servicesChanged
START: getServices !
getServices duration: 0.00301790237427
START: getServices !
getServices duration: 0.00303387641907
START: getServices !
getServices duration: 6.37309789658


It seems that those timeout above are corresponding to the
append_nameservers() log entries

connmand[6082]: src/service.c:append_ipv4() ipv4 0x1be1210 state online
connmand[6082]: src/ipconfig.c:__connman_ipconfig_append_ipv4()
connmand[6082]: src/ipconfig.c:__connman_ipconfig_append_ipv4config()
connmand[6082]: src/service.c:append_ipv6() ipv6 0x1be1300 state idle
connmand[6082]: src/ipconfig.c:__connman_ipconfig_append_ipv6config()
connmand[6082]: src/service.c:append_nameservers() 0x1be6090
connmand[6082]: src/service.c:append_nameservers() servers[0] 192.168.100.4
connmand[6082]: src/service.c:append_nameservers() servers[1] 192.168.100.1
connmand[6082]: src/storage.c:storage_load() Loading /var/lib/connman/settings
connmand[6082]: src/service.c:append_proxy()
connmand[6082]: src/service.c:append_provider() 0x1bdc520 (nil)

Could it be that we block there?


After some more testing it is clear that ConnMan is working fine.

while sleep 1 ; do time connmanctrl services ; done

The Python script was running and in parallel the avove line did never 
block.


And whenever I saw the getServices() blockin, connmanctl just keept 
working fine.


From that I would say the problem is on the Python script side.

cheers,
daniel
___
connman mailing list
connman@connman.net
https://lists.connman.net/mailman/listinfo/connman


D-Bus Timeouts

2013-01-14 Thread Daniel Wagner

Hi,

There seems to be some oddity with getServices() and D-Bus timeout. I 
was able to reproduce (not very often) this on my 'big' machine but it 
seems to hit more often on embedded boards and a wifi scan triggering.


Here is a simplified version the script lufie is using. Maybe I am able
to get also the corresponding connman log when it happens again.

cheers,
daniel

a typical log:
connmanMonitor::propertyChanged
connmanMonitor::servicesChanged
START: getServices !
getServices duration: 0.00309801101685
START: getServices !
getServices duration: 0.0032811164856
START: getServices !
getServices duration: 0.00319886207581
START: getServices !
getServices duration: 0.00316905975342


when something blocks:

connmanMonitor::servicesChanged
START: getServices !
getServices duration: 0.00296497344971
START: getServices !
getServices duration: 0.00302910804749
START: getServices !
getServices duration: 0.00310301780701
connmanMonitor::managerPropertyChanged
connmanMonitor::propertyChanged
connmanMonitor::managerPropertyChanged
connmanMonitor::propertyChanged
connmanMonitor::servicesChanged
START: getServices !
getServices duration: 0.00301790237427
START: getServices !
getServices duration: 0.00303387641907
START: getServices !
getServices duration: 6.37309789658

or:

START: getServices !
getServices duration: 0.00313091278076
START: getServices !
getServices duration: 0.00323581695557
START: getServices !
getServices duration: 0.00313687324524
START: getServices !
getServices duration: 0.00302600860596
START: getServices !
getServices duration: 20.4522678852
connmanMonitor::managerPropertyChanged
connmanMonitor::propertyChanged
connmanMonitor::servicesChanged
START: getServices !
getServices duration: 0.00313305854797
START: getServices !
# Based on lufie's work: http://sprunge.us/ZddQ
import sys
import threading
import time
import dbus
import time
import dbus.mainloop.glib
import dbus.service
import gobject
import traceback
import os
from sys import stdout

dbus.mainloop.glib.DBusGMainLoop(set_as_default=True)

test_services = True
dbusConnmanManager = None

def readServices():
last_read_services = 0

while test_services == True:
start = time.time()
print(START: getServices !)
dbusServices = dbusConnmanManager.GetServices()
print(getServices duration:  + str(time.time() - start))
time.sleep(0.5)


class agentLoop(threading.Thread):
def __init__(self, dbusSystemBus):

print(agentLoop::__init__)

self.dbusSystemBus = dbusSystemBus
self.wifiAgentPath = /test/agent_wifi
self.vpnAgentPath = /test/agent_vpn

threading.Thread.__init__(self)

def run(self):

self.dbusSystemBus.watch_name_owner(
'net.connman.vpn', self.vpnNameOwnerChanged)
self.dbusSystemBus.watch_name_owner(
'net.connman', self.nameOwnerChanged)

try:
print(Connman VPN and Wireless Agent started.)
self.mainLoop = gobject.MainLoop()
self.mainLoop.run()
print(Connman VPN and Wireless Agent stopped.)
except:
pass

def nameOwnerChanged(self, proxy):

print(connman::agentLoop::nameOwnerChanged)

if proxy:
print(connman is connected to system bus)

self.dbusConnmanManager = dbus.Interface(self.dbusSystemBus.get_object('net.connman', /), 'net.connman.Manager')
self.wifiAgent = wifiAgent(
self.dbusSystemBus, self.wifiAgentPath)

self.dbusConnmanManager.RegisterAgent(self.wifiAgentPath)

self.dbusConnmanManager = None
else:
print(connman is disconnected from system bus)

if hasattr(self, wifiAgent):
self.wifiAgent.remove_from_connection(
self.dbusSystemBus, self.wifiAgentPath)
self.wifiAgent = None

def vpnNameOwnerChanged(self, proxy):

print(connman::agentLoop::vpnNameOwnerChanged)

if proxy:
print(vpnd is connected to system bus)

self.dbusConnmanVpnManager = dbus.Interface(self.dbusSystemBus.get_object('net.connman.vpn', /), 'net.connman.vpn.Manager')
self.vpnAgent = vpnAgent(
self.dbusSystemBus, self.vpnAgentPath)

self.dbusConnmanVpnManager.RegisterAgent(self.vpnAgentPath)

self.dbusConnmanVpnManager = None
else:
print(vpnd is disconnected from system bus)

if hasattr(self, vpnAgent):
self.VpnAgent.remove_from_connection(
self.dbusSystemBus, self.vpnAgentPath)
self.VpnAgent = None

def exit(self):

self.mainLoop.quit()

self.dbusConnmanVpnManager = dbus.Interface(self.dbusSystemBus.get_object('net.connman.vpn', /), 'net.connman.vpn.Manager')
self.dbusConnmanManager = dbus.Interface(self.dbusSystemBus.get_object(
'net.connman', /), 

Re: D-Bus Timeouts

2013-01-14 Thread Daniel Wagner
On 14.01.2013 14:08, Daniel Wagner wrote:
 when something blocks:
 
 connmanMonitor::servicesChanged
 START: getServices !
 getServices duration: 0.00296497344971
 START: getServices !
 getServices duration: 0.00302910804749
 START: getServices !
 getServices duration: 0.00310301780701
 connmanMonitor::managerPropertyChanged
 connmanMonitor::propertyChanged
 connmanMonitor::managerPropertyChanged
 connmanMonitor::propertyChanged
 connmanMonitor::servicesChanged
 START: getServices !
 getServices duration: 0.00301790237427
 START: getServices !
 getServices duration: 0.00303387641907
 START: getServices !
 getServices duration: 6.37309789658

It seems that those timeout above are corresponding to the 
append_nameservers() log entries

connmand[6082]: src/service.c:append_ipv4() ipv4 0x1be1210 state online
connmand[6082]: src/ipconfig.c:__connman_ipconfig_append_ipv4() 
connmand[6082]: src/ipconfig.c:__connman_ipconfig_append_ipv4config() 
connmand[6082]: src/service.c:append_ipv6() ipv6 0x1be1300 state idle
connmand[6082]: src/ipconfig.c:__connman_ipconfig_append_ipv6config() 
connmand[6082]: src/service.c:append_nameservers() 0x1be6090
connmand[6082]: src/service.c:append_nameservers() servers[0] 192.168.100.4
connmand[6082]: src/service.c:append_nameservers() servers[1] 192.168.100.1
connmand[6082]: src/storage.c:storage_load() Loading /var/lib/connman/settings
connmand[6082]: src/service.c:append_proxy() 
connmand[6082]: src/service.c:append_provider() 0x1bdc520 (nil)

Could it be that we block there?
___
connman mailing list
connman@connman.net
http://lists.connman.net/listinfo/connman