1# Copyright (c) 2011 The Chromium OS Authors. All rights reserved.
2# Use of this source code is governed by a BSD-style license that can be
3# found in the LICENSE file.
4
5import dbus
6import glib
7import gobject
8import logging
9import os
10import pty
11import re
12import subprocess
13import traceback
14
15from autotest_lib.client.bin import test
16from autotest_lib.client.bin import utils
17from autotest_lib.client.common_lib import error
18from autotest_lib.client.cros.cellular import mm
19from autotest_lib.client.cros.cellular import modem_utils
20
21TEST_TIMEOUT = 120
22
23# Preconditions for starting
24START_DEVICE_PRESENT = 'start_device_present'
25START_UDEVADM_RUNNING = 'start_udevadm_running'
26
27# ModemManager service enters, leaves bus
28MM_APPEARED = 'modem_manager_appeared'
29MM_DISAPPEARED = 'modem_manager_disappeared'
30
31# userlevel UDEV sees the modem come and go
32MODEM_APPEARED = 'modem_appeared'
33MODEM_DISAPPEARED = 'modem_disappeared'
34
35class TestEventLoop(object):
36  """Common tools for running glib event loops."""
37  def __init__(self):
38    # The glib mainloop sinks exceptions thrown by event handlers, so we
39    # provide a wrapper that saves the exceptions so the event loop can
40    # re-raise them.
41
42    # TODO(rochberg): The rethrown exceptions come with the stack of the
43    # rethrow point, not the original exceptions.  Fix.
44    self.to_raise = None
45
46    # Autotest won't continue until our children are dead.  Keep track
47    # of them
48    self.to_kill = []
49
50  def ExceptionWrapper(self, f):
51    """Returns a wrapper that calls f and saves exceptions for re-raising."""
52    def to_return(*args, **kwargs):
53      try:
54        return f(*args, **kwargs)
55      except Exception, e:
56        logging.info('Caught: ' + traceback.format_exc())
57        self.to_raise = e
58        return True
59    return to_return
60
61  def Popen(self, *args, **kwargs):
62    """Builds a supbrocess.Popen, saves a copy for later kill()ing."""
63    to_return = subprocess.Popen(*args, **kwargs)
64    self.to_kill.append(to_return)
65    return to_return
66
67  def KillSubprocesses(self):
68    for victim in self.to_kill:
69      victim.kill()
70
71class GobiDesyncEventLoop(TestEventLoop):
72  def __init__(self, test_env):
73    super(GobiDesyncEventLoop, self).__init__()
74    self.test_env = test_env
75    self.dbus_signal_receivers = []
76
77    # Start conditions; once these have been met, call StartTest.
78    # This makes sure that cromo and udevadm are ready to use
79    self.remaining_start_conditions = set([START_DEVICE_PRESENT,
80                                           START_UDEVADM_RUNNING])
81
82    # We want to see all of these events before we're done
83    self.remaining_events = set([MM_APPEARED, MM_DISAPPEARED,
84                                 MODEM_APPEARED, MODEM_DISAPPEARED, ])
85
86
87    # udevadm monitor output for user-level notifications of device
88    # add and remove
89    # UDEV  [1296763045.687859] add      /devices/virtual/QCQMI/qcqmi0 (QCQMI)
90    self.udev_qcqmi = re.compile(
91        r'UDEV.*\s(?P<action>\w+).*/QCQMI/qcqmi')
92
93  def NameOwnerChanged(self, name, old, new):
94    if name != 'org.chromium.ModemManager':
95      return
96    if not new:
97      self.remaining_events.remove(MM_DISAPPEARED)
98    elif not old:
99      if MM_DISAPPEARED in self.remaining_events:
100        raise Exception('Saw cromo appear before it disappeared')
101      self.remaining_events.remove(MM_APPEARED)
102    return True
103
104  def ModemAdded(self, path):
105    """Clock the StartIfReady() state machine when we see a modem added."""
106    logging.info('Modem %s added' % path)
107    self.StartIfReady()         # Checks to see if the modem is present
108
109  def TimedOut(self):
110    raise Exception('Timed out: still waiting for: '
111                    + str(self.remaining_events))
112
113  def UdevOutputReceived(self, source, condition):
114    if condition & glib.IO_IN:
115      output = os.read(source.fileno(), 65536)
116
117      # We don't want to start the test until udevadm is running
118      if 'KERNEL - the kernel uevent' in output:
119        self.StartIfReady(START_UDEVADM_RUNNING)
120
121      for line in output.split('\r\n'):
122        logging.info(line)
123        match = self.udev_qcqmi.search(line)
124        if not match:
125          continue
126        action = match.group('action')
127        logging.info('Action:[%s]' % action)
128        if action == 'add':
129          if MM_DISAPPEARED in self.remaining_events:
130            raise Exception('Saw modem appear before it disappeared')
131          self.remaining_events.remove(MODEM_APPEARED)
132
133        elif action == 'remove':
134          self.remaining_events.remove(MODEM_DISAPPEARED)
135    return True
136
137
138  def StartIfReady(self, condition_to_remove=None):
139    """Call StartTest when remaining_start_conditions have been met."""
140    if condition_to_remove:
141      self.remaining_start_conditions.discard(condition_to_remove)
142
143    try:
144      if (START_DEVICE_PRESENT in self.remaining_start_conditions and
145          mm.PickOneModem('Gobi')):
146        self.remaining_start_conditions.discard(START_DEVICE_PRESENT)
147    except dbus.exceptions.DBusException, e:
148      if e.get_dbus_name() != 'org.freedesktop.DBus.Error.NoReply':
149        raise
150
151    if self.remaining_start_conditions:
152      logging.info('Not starting until: %s' % self.remaining_start_conditions)
153    else:
154      logging.info('Preconditions satisfied')
155      self.StartTest()
156      self.remaining_start_conditions = ['dummy entry so we do not start twice']
157
158  def RegisterDbusSignal(self, *args, **kwargs):
159    """Register signal receiver with dbus and our cleanup list."""
160    self.dbus_signal_receivers.append(
161        self.test_env.bus.add_signal_receiver(*args, **kwargs))
162
163  def CleanupDbusSignalReceivers(self):
164    for signal_match in self.dbus_signal_receivers:
165      signal_match.remove()
166
167  def RegisterForDbusSignals(self):
168    # Watch cromo leave the bus when it terminates and return when it
169    # is restarted
170    self.RegisterDbusSignal(self.ExceptionWrapper(self.NameOwnerChanged),
171                            bus_name='org.freedesktop.DBus',
172                            signal_name='NameOwnerChanged')
173
174    # Wait for cromo to report that the modem is present.
175    self.RegisterDbusSignal(self.ExceptionWrapper(self.ModemAdded),
176                            bus_name='org.freedesktop.DBus',
177                            signal_name='DeviceAdded',
178                            dbus_interface='org.freedesktop.ModemManager')
179
180  def RegisterForUdevMonitor(self):
181    # have udevadm output to a pty so it will line buffer
182    (master, slave) = pty.openpty()
183    monitor = self.Popen(['udevadm', 'monitor'],
184                         stdout=os.fdopen(slave),
185                         bufsize=1)
186
187    glib.io_add_watch(os.fdopen(master),
188                      glib.IO_IN | glib.IO_HUP,
189                      self.ExceptionWrapper(self.UdevOutputReceived))
190
191  def Wait(self, timeout_seconds):
192    self.RegisterForDbusSignals()
193    self.RegisterForUdevMonitor()
194    gobject.timeout_add(timeout_seconds * 1000,
195                        self.ExceptionWrapper(self.TimedOut))
196
197    # Check to see if the modem is present and remove that from the
198    # start preconditions if need be
199    self.StartIfReady()
200
201    context = gobject.MainLoop().get_context()
202    while self.remaining_events and not self.to_raise:
203      logging.info('Waiting for: ' + str(self.remaining_events))
204      context.iteration()
205
206    modem_utils.ClearGobiModemFaultInjection()
207    self.KillSubprocesses()
208    self.CleanupDbusSignalReceivers()
209    if self.to_raise:
210      raise self.to_raise
211    logging.info('Done waiting for events')
212
213
214class RegularOperationTest(GobiDesyncEventLoop):
215  """This covers the case where the modem makes an API call that
216     returns a "we've lost sync" error that should cause a reboot."""
217
218  def __init__(self, test_env):
219    super(RegularOperationTest, self).__init__(test_env)
220
221  def StartTest(self):
222    self.test_env.modem.GobiModem().InjectFault('SdkError', 12)
223    self.test_env.modem.SimpleModem().GetStatus()
224
225
226class DataConnectTest(GobiDesyncEventLoop):
227  """Test the special-case code path where we receive an error from
228     StartDataSession.  If we're not also disabling at the same time,
229     this should behave the same as other desync errors."""
230
231  def __init__(self, test_env):
232    super(DataConnectTest, self).__init__(test_env)
233
234  def ignore(self, *args, **kwargs):
235    logging.info('ignoring')
236    pass
237
238  def StartTest(self):
239    gobi = self.test_env.modem.GobiModem()
240    gobi.InjectFault('AsyncConnectSleepMs', 1000)
241    gobi.InjectFault('ConnectFailsWithErrorSendingQmiRequest', 1)
242    self.test_env.modem.SimpleModem().Connect(
243            {}, reply_handler=self.ignore, error_handler=self.ignore)
244
245class ApiConnectTest(GobiDesyncEventLoop):
246  """Test the special-case code on errors connecting to the API. """
247  def __init__(self, test_env):
248    super(ApiConnectTest, self).__init__(test_env)
249
250  def StartTest(self):
251    self.test_env.modem.Enable(False)
252
253    saw_exception = False
254    # Failures on API connect are a different code path
255    self.test_env.modem.GobiModem().InjectFault('SdkError', 1)
256    try:
257      self.test_env.modem.Enable(True)
258    except dbus.exceptions.DBusException:
259      saw_exception = True
260    if not saw_exception:
261      raise error.TestFail('Enable returned when it should have crashed')
262
263class EnableDisableTest():
264  """Test that the Enable and Disable technology functions work."""
265
266  def __init__(self, test_env):
267    self.test_env = test_env
268
269  def CompareModemPowerState(self, modem, expected_state):
270    """Compare the power state of a modem to an expected state."""
271    props = modem.GetModemProperties()
272    state = props['Enabled']
273    logging.info('Modem Enabled = %s' % state)
274    return state == expected_state
275
276  def CompareDevicePowerState(self, device, expected_state):
277    """Compare the shill device power state to an expected state."""
278    device_properties = device.GetProperties(utf8_strings=True);
279    state = device_properties['Powered']
280    logging.info('Device Enabled = %s' % state)
281    return state == expected_state
282
283  def Test(self):
284    """Test that the Enable and Disable technology functions work.
285
286       The expectation is that by using enable technology shill
287       will change the power state of the device by requesting that
288       the modem manager modem be either Enabled or Disabled.  The
289       state tracked by shill should not change until *after* the
290       modem state has changed.  Thus after Enabling or Disabling the
291       technology, we wait until the shill device state changes,
292       and then assert that the modem state has also changed, without
293       having to wait again.
294
295       Raises:
296         error.TestFail - if the shill device or the modem manager
297           modem is not in the expected state
298    """
299    device = self.test_env.shill.find_cellular_device_object()
300
301    for i in range(2):
302      # Enable technology, ensure that device and modem are enabled.
303      self.test_env.shill.manager.EnableTechnology('cellular')
304      utils.poll_for_condition(
305          lambda: self.CompareDevicePowerState(device, True),
306          error.TestFail('Device Failed to enter state Powered=True'))
307      if not self.CompareModemPowerState(self.test_env.modem, True):
308        raise error.TestFail('Modem Failed to enter state Enabled')
309
310      # Disable technology, ensure that device and modem are disabled.
311      self.test_env.shill.manager.DisableTechnology('cellular')
312      utils.poll_for_condition(
313          lambda: self.CompareDevicePowerState(device, False),
314          error.TestFail('Device Failed to enter state Powered=False'))
315      if not self.CompareModemPowerState(self.test_env.modem, False):
316        raise error.TestFail('Modem Failed to enter state Disabled')
317
318
319class cellular_GobiRecoverFromDesync(test.test):
320  version = 1
321
322  def run_test(self, test_env, test):
323    with test_env:
324      try:
325        test()
326      finally:
327        modem_utils.ClearGobiModemFaultInjection()
328
329  def run_once(self, test_env, cycles=1, min=1, max=20):
330    logging.info('Testing failure during DataConnect')
331    self.run_test(test_env,
332                  lambda: DataConnectTest(test_env).Wait(TEST_TIMEOUT))
333
334    logging.info('Testing failure while in regular operation')
335    self.run_test(test_env,
336                  lambda: RegularOperationTest(test_env).Wait(TEST_TIMEOUT))
337
338    logging.info('Testing failure during device initialization')
339    self.run_test(test_env,
340                  lambda: ApiConnectTest(test_env).Wait(TEST_TIMEOUT))
341
342    logging.info('Testing that Enable and Disable technology still work')
343    self.run_test(test_env,
344                  lambda: EnableDisableTest(test_env).Test())
345