1# Copyright (c) 2018 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"""Autotest for Logitech Meetup firmware updater."""
5
6import logging
7import os
8import re
9import time
10
11
12from autotest_lib.client.common_lib import error
13from autotest_lib.client.common_lib.cros import power_cycle_usb_util
14from autotest_lib.client.common_lib.cros.cfm.usb import cfm_usb_devices
15from autotest_lib.server import test
16
17
18POWER_CYCLE_WAIT_TIME_SEC = 20
19
20
21class enterprise_CFM_LogitechMeetupUpdater(test.test):
22    """
23    Logitech Meetup firmware test on Chrome For Meeting devices
24    The test follows the following steps
25        1) Check if the filesystem is writable
26           If not make the filesystem writable and reboot
27        2) Backup the existing firmware file on DUT
28        3) Copy the older firmware files to DUT
29        4) Force update older firmware on Meetup Camera
30        5) Restore the original firmware files on DUT
31        4) Power cycle usb port to simulate unplug/replug of device which
32           should initiate a firmware update
33        5) Wait for firmware update to finish and check firmware version
34        6) Cleanup
35
36    """
37
38    version = 1
39
40    def initialize(self, host):
41        """
42        Initializes the class.
43
44        Stores the firmware file path.
45        Gets the board type.
46        Reads the current firmware versions.
47        """
48
49        self.host = host
50        self.log_file = '/tmp/logitech-updater.log'
51        self.fw_path_base = '/lib/firmware/logitech'
52        self.fw_pkg_origin = 'meetup'
53        self.fw_pkg_backup = 'meetup_backup'
54        self.fw_pkg_test = 'meetup_184'
55        self.fw_pkg_files = ['meetup_audio.bin',
56                             'meetup_audio_logicool.bin',
57                             'meetup_ble.bin',
58                             'meetup_codec.bin',
59                             'meetup_eeprom_logicool.s19',
60                             'meetup_eeprom.s19',
61                             'meetup_video.bin',
62                             'meetup_audio.bin.sig',
63                             'meetup_audio_logicool.bin.sig',
64                             'meetup_ble.bin.sig',
65                             'meetup_codec.bin.sig',
66                             'meetup_eeprom_logicool.s19.sig',
67                             'meetup_eeprom.s19.sig',
68                             'meetup_video.bin.sig']
69        self.fw_path_test = os.path.join(self.fw_path_base,
70                                         self.fw_pkg_test)
71        self.fw_path_origin = os.path.join(self.fw_path_base,
72                                           self.fw_pkg_origin)
73        self.fw_path_backup = os.path.join(self.fw_path_base,
74                                           self.fw_pkg_backup)
75        self.board = self.host.get_board().split(':')[1]
76        self.vid = cfm_usb_devices.LOGITECH_MEETUP.vendor_id
77        self.pid = cfm_usb_devices.LOGITECH_MEETUP.product_id
78        self.org_fw_ver = self.get_image_fw_ver()
79
80    def cleanup(self):
81        """
82        Cleanups after tests.
83
84        Removes the test firmware.
85        Restores the original firmware files.
86        Flashes the camera to original firmware if needed.
87        """
88
89        # Delete test firmware package.
90        cmd = 'rm -rf {}'.format(self.fw_path_test)
91        self.host.run(cmd)
92
93        # Delete the symlink created.
94        cmd = 'rm {}'.format(self.fw_path_origin)
95        self.host.run(cmd)
96
97        # Move the backup package back.
98        cmd = 'mv {} {}'.format(self.fw_path_backup, self.fw_path_origin)
99        self.host.run(cmd)
100
101        # Do not leave the camera with test (older) firmware.
102        if not self.is_device_firmware_equal_to(self.org_fw_ver):
103            logging.debug('Meetup device has old firmware after test'
104                          'Flashing new firmware')
105            self.flash_fw()
106
107        super(enterprise_CFM_LogitechMeetupUpdater, self).cleanup()
108
109    def _run_cmd(self, command, ignore_status=True):
110        """
111        Runs command line on DUT, wait for completion and return the output.
112
113        @param command: command line to run in dut.
114        @param ignore_status: if true ignore the status return by command
115
116        @returns the command output
117
118        """
119
120        logging.debug('Execute: %s', command)
121
122        result = self.host.run(command, ignore_status=ignore_status)
123        if result.stderr:
124            output = result.stderr
125        else:
126            output = result.stdout
127        logging.debug('Output: %s', output)
128        return output
129
130    def make_rootfs_writable(self):
131        """Checks and makes root filesystem writable."""
132
133        if not self.is_filesystem_readwrite():
134            logging.info('DUT root file system is not writable. '
135                         'Converting it writable...')
136            self.convert_rootfs_writable()
137        else:
138            logging.info('DUT root file system is writable.')
139
140    def convert_rootfs_writable(self):
141        """Makes DUT rootfs writable."""
142
143        logging.info('Disabling rootfs verification...')
144        self.remove_rootfs_verification()
145
146        logging.info('Rebooting...')
147        self.host.reboot()
148
149        logging.info('Remounting..')
150        cmd = 'mount -o remount,rw /'
151        self.host.run(cmd)
152
153    def remove_rootfs_verification(self):
154        """Removes rootfs verification."""
155
156        # 2 & 4 are default partitions, and the system boots from one of them.
157        # Code from chromite/scripts/deploy_chrome.py
158        KERNEL_A_PARTITION = 2
159        KERNEL_B_PARTITION = 4
160
161        cmd_template = ('/usr/share/vboot/bin/make_dev_ssd.sh'
162                        ' --partitions "%d %d"'
163                        ' --remove_rootfs_verification --force')
164        cmd = cmd_template % (KERNEL_A_PARTITION, KERNEL_B_PARTITION)
165        self.host.run(cmd)
166
167    def is_filesystem_readwrite(self):
168        """Checks if the root file system is writable."""
169
170        # Query the DUT's filesystem /dev/root and check whether it is rw
171
172        cmd = 'cat /proc/mounts | grep "/dev/root"'
173        result = self._run_cmd(cmd)
174        fields = re.split(' |,', result)
175
176        # Result of grep will be of the following format
177        # /dev/root / ext2 ro,seclabel <....truncated...> => readonly
178        # /dev/root / ext2 rw,seclabel <....truncated...> => readwrite
179        is_writable = fields.__len__() >= 4 and fields[3] == 'rw'
180        return is_writable
181
182    def fw_ver_from_output_str(self, cmd_output):
183        """
184        Parse firmware version of logitech-updater output.
185
186        logitech-updater output differs for image_version and device_version
187        This function finds the line which contains string "Meetup" and parses
188        succeding lines. Each line is split on spaces (after collapsing spaces)
189        and index 1 gives component name (ex. Eeprom) and index 3 gives the
190        firmware version (ex. 1.14)
191        The actual output is given below.
192
193        logitech-updater --image_version
194
195        [INFO:main.cc(105)] PTZ Pro 2 Versions:
196        [INFO:main.cc(59)] Video version:  2.0.175
197        [INFO:main.cc(61)] Eeprom version: 1.6
198        [INFO:main.cc(63)] Mcu2 version:   3.9
199
200        [INFO:main.cc(105)] MeetUp Versions:
201        [INFO:main.cc(59)] Video version:  1.0.197
202        [INFO:main.cc(61)] Eeprom version: 1.14
203        [INFO:main.cc(65)] Audio version:  1.0.239
204        [INFO:main.cc(67)] Codec version:  8.0.216
205        [INFO:main.cc(69)] BLE version:    1.0.121
206
207        logitech-updater  --device_version
208
209        [INFO:main.cc(88)] Device name:    Logitech MeetUp
210        [INFO:main.cc(59)] Video version:  1.0.197
211        [INFO:main.cc(61)] Eeprom version: 1.14
212        [INFO:main.cc(65)] Audio version:  1.0.239
213        [INFO:main.cc(67)] Codec version:  8.0.216
214        [INFO:main.cc(69)] BLE version:    1.0.121
215
216
217        """
218
219        logging.debug('Parsing output from updater %s', cmd_output)
220        if 'MeetUp image not found' in cmd_output or 'MeetUp' not in cmd_output:
221           raise error.TestFail('MeetUp image not found on DUT')
222        try:
223            version = {}
224            output = cmd_output.split('\n')
225            start_line = -1
226
227            # Find the line of the output with string "Meetup
228            for i, l in enumerate(output):
229                if 'MeetUp' in l:
230                    start_line = i
231                    break
232
233            if start_line == -1:
234                raise error.TestFail('Meetup version not found'
235                                     ' in updater output')
236
237            output = output[start_line+1:start_line+6]
238            logging.debug('Parsing Meetup firmware info %s', str(output))
239            for l in output:
240
241                # Output lines are of the format
242                # [INFO:main.cc(59)] Video version:  1.0.197
243                l = ' '.join(l.split())  # Collapse multiple spaces to one space
244                parts = l.split(' ')  # parts[1] is "Video" parts[3] is 1.0.197
245                version[parts[1]] = parts[3]
246            logging.debug('Version is %s', str(version))
247            return version
248        except:
249            logging.error('Error while parsing logitech-updater output')
250            raise
251
252    def get_updater_output(self, cmd):
253        """Get updater output while avoiding transient failures."""
254
255        NUM_RETRIES = 3
256        WAIT_TIME = 5
257        for _ in range(NUM_RETRIES):
258            output = self._run_cmd(cmd)
259            if 'Failed to read' in output:
260                time.sleep(WAIT_TIME)
261                continue
262            return output
263
264    def get_image_fw_ver(self):
265        """Get the version of firmware on DUT."""
266
267        output = self.get_updater_output('logitech-updater --image_version'
268                                         ' --log_to=stdout')
269        return self.fw_ver_from_output_str(output)
270
271    def get_device_fw_ver(self):
272        """Get the version of firmware on Meetup device."""
273
274        output = self.get_updater_output('logitech-updater --device_version'
275                                         ' --log_to=stdout')
276        return self.fw_ver_from_output_str(output)
277
278    def copy_test_firmware(self):
279        """Copy test firmware from server to DUT."""
280
281        current_dir = os.path.dirname(os.path.realpath(__file__))
282        src_firmware_path = os.path.join(current_dir, self.fw_pkg_test)
283        dst_firmware_path = self.fw_path_base
284        logging.info('Copy firmware from (%s) to (%s).', src_firmware_path,
285                     dst_firmware_path)
286        self.host.send_file(src_firmware_path, dst_firmware_path,
287                            delete_dest=True)
288
289    def trigger_updater(self):
290        """Trigger udev rule to run fw updater by power cycling the usb."""
291
292        try:
293            power_cycle_usb_util.power_cycle_usb_vidpid(self.host, self.board,
294                                                        self.vid, self.pid)
295        except KeyError:
296            raise error.TestFail('Counld\'t find target device: '
297                                 'vid:pid {}:{}'.format(self.vid, self.pid))
298
299    def wait_for_meetup_device(self):
300        """
301        Wait for Meetup device device to be enumerated.
302
303        Check if a device with given (vid,pid) is present.
304        Timeout after wait_time seconds. Default 30 seconds
305        """
306
307        TIME_SLEEP = 10
308        NUM_ITERATIONS = 3
309        WAIT_TIME = TIME_SLEEP * NUM_ITERATIONS
310
311        logging.debug('Waiting for Meetup device')
312        for _ in range(NUM_ITERATIONS):
313            res = power_cycle_usb_util.get_port_number_from_vidpid(
314                self.host, self.vid, self.pid)
315            (bus_num, port_num) = res
316            if bus_num is not None and port_num is not None:
317                logging.debug('Meetup device detected')
318                return
319            else:
320                logging.debug('Meetup device not detected.'
321                              'Waiting for (%s) seconds', TIME_SLEEP)
322                time.sleep(TIME_SLEEP)
323
324        logging.error('Unable to detect the device after (%s) seconds.'
325                      'Timing out...', WAIT_TIME)
326        raise error.TestFail('Target device not detected.')
327
328    def setup_fw(self, firmware_package):
329        """Setup firmware package that is going to be used for updating."""
330
331        firmware_path = os.path.join(self.fw_path_base, firmware_package)
332        cmd = 'ln -sfn {} {}'.format(firmware_path, self.fw_path_origin)
333        self.host.run(cmd)
334
335    def flash_fw(self, force=False):
336        """Flash certain firmware to device.
337
338        Run logitech firmware updater on DUT to flash the firmware setuped
339        to target device (PTZ Pro 2).
340
341        @param force: run with force update, will bypass fw version check.
342
343        """
344
345        cmd = ('/usr/sbin/logitech-updater --log_to=stdout --update_components'
346               ' --lock')
347        if force:
348            cmd += ' --force'
349        output = self._run_cmd(cmd)
350        return output
351
352    def print_fw_version(self, version, info_str=''):
353        """Pretty print Meetup firmware version."""
354
355        if info_str:
356            print info_str
357        print 'Video version: ', version['Video']
358        print 'Eeprom version: ', version['Eeprom']
359        print 'Audio version: ', version['Audio']
360        print 'Codec version: ', version['Codec']
361        print 'BLE version: ', version['BLE']
362
363    def is_device_firmware_equal_to(self, expected_ver):
364        """Check that the device fw version is equal to given version."""
365
366        device_fw_version = self.get_device_fw_ver()
367        if  device_fw_version != expected_ver:
368            logging.error('Device firmware version is not the expected version')
369            self.print_fw_version(device_fw_version, 'Device firmware version')
370            self.print_fw_version(expected_ver, 'Expected firmware version')
371            return False
372        else:
373            return True
374
375    def flash_old_firmware(self):
376        """Flash old (test) version of firmware on the device."""
377
378        # Flash old FW to device.
379        self.setup_fw(self.fw_pkg_test)
380        test_fw_ver = self.get_image_fw_ver()
381        self.print_fw_version(test_fw_ver, 'Test firmware version')
382        output = self.flash_fw(force=True)
383        time.sleep(POWER_CYCLE_WAIT_TIME_SEC)
384        with open(self.log_file, 'w') as f:
385            delim = '-' * 8
386            f.write('{}Log info for writing old firmware{}'
387                    '\n'.format(delim, delim))
388            f.write(output)
389        if not self.is_device_firmware_equal_to(test_fw_ver):
390            raise error.TestFail('Flashing old firmware failed')
391        logging.info('Device flashed with test firmware')
392
393    def backup_original_firmware(self):
394        """Backup existing firmware on DUT."""
395        # Copy old FW to device.
396        cmd = 'mv {} {}'.format(self.fw_path_origin, self.fw_path_backup)
397        self.host.run(cmd)
398
399    def is_updater_running(self):
400        """Checks if the logitech-updater is running."""
401
402        cmd = 'logitech-updater --lock --device_version --log_to=stdout'
403        output = self._run_cmd(cmd)
404        return 'There is another logitech-updater running' in output
405
406    def wait_for_updater(self):
407        """Wait logitech-updater to stop or timeout after 6 minutes."""
408
409        NUM_ITERATION = 12
410        WAIT_TIME = 30  # seconds
411        logging.debug('Wait for any currently running updater to finish')
412        for _ in range(NUM_ITERATION):
413            if self.is_updater_running():
414                logging.debug('logitech-updater is running.'
415                              'Waiting for 30 seconds')
416                time.sleep(WAIT_TIME)
417            else:
418                logging.debug('logitech-updater not running')
419                return
420        logging.error('logitech-updater is still running after 6 minutes')
421
422    def test_firmware_update(self):
423        """Trigger firmware updater and check device firmware version."""
424
425        # Simulate hotplug to run FW updater.
426        logging.info('Setup original firmware')
427        self.setup_fw(self.fw_pkg_backup)
428        logging.info('Simulate hot plugging the device')
429        self.trigger_updater()
430        self.wait_for_meetup_device()
431
432        # The firmware check will fail if the check runs in a short window
433        # between the device being detected and the firmware updater starting.
434        # Adding a delay to reduce the chance of that scenerio.
435        time.sleep(POWER_CYCLE_WAIT_TIME_SEC)
436
437        self.wait_for_updater()
438
439        if not self.is_device_firmware_equal_to(self.org_fw_ver):
440            raise error.TestFail('Camera not updated to new firmware')
441        logging.info('Firmware update was completed successfully')
442
443    def run_once(self):
444        """
445        Entry point for test.
446
447        The following actions are performed in this test.
448        - Device is flashed with older firmware.
449        - Powercycle usb port to simulate hotplug inorder to start the updater.
450        - Check that the device is updated with newer firmware.
451        """
452
453        # Check if updater is already running
454        self.wait_for_updater()
455
456        self.print_fw_version(self.org_fw_ver,
457                              'Original firmware version on DUT')
458        self.print_fw_version(self.get_device_fw_ver(),
459                              'Firmware version on Meetup device')
460
461        self.make_rootfs_writable()
462        self.backup_original_firmware()
463
464        # Flash test firmware version
465        self.copy_test_firmware()
466        self.flash_old_firmware()
467
468        # Test firmware update
469        self.test_firmware_update()
470        logging.info('Logitech Meetup firmware updater test was successful')
471