Bug 48881 - Cannot install owncloud: TypeError: sequence item 2: expected string, NoneType found
Cannot install owncloud: TypeError: sequence item 2: expected string, NoneTyp...
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: App Center
UCS 4.4
Other Linux
: P5 normal (vote)
: UCS 4.4-0-errata
Assigned To: Felix Botner
Dirk Wiesenthal
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2019-03-06 15:04 CET by Florian Best
Modified: 2020-08-14 12:50 CEST (History)
3 users (show)

See Also:
What kind of report is it?: Development Internal
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number: 2019052721000278, 2019041721000379, 2019022421000216, 2019060421000014
Bug group (optional): External feedback
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Florian Best univentionstaff 2019-03-06 15:04:17 CET
using the test appcenter and the following command:
univention-app install --do-not-install-master-packages-remotely --password=univention --noninteractive owncloud

Creating data directories for owncloud...                                                                                                                                                                                                                                        
Copying /var/cache/univention-appcenter/appcenter-test.software-univention.de/4.3/owncloud_20190226114121.schema                                                                                                                                                                 
Registering UCR for owncloud                                                                                                                                                                                                                                                     
Marking 4.3/owncloud=10.1.0-2019-02-27 as installed                                                                                                                                                                                                                              
File: /etc/univention/service.info/services/univention-appcenter.cfg                                                                                                                                                                                                             
Multifile: /etc/postgresql/9.6/main/pg_hba.conf                                                                                                                                                                                                                                  
File: /usr/share/univention-portal/apps.json                                                                                                                                                                                                                                     
Setting ports for apache proxy                                                                                                                                                                                                                                                   
Multifile: /etc/apache2/sites-available/000-default.conf                                                                                                                                                                                                                         
Multifile: /etc/apache2/sites-available/default-ssl.conf                                                                                                                                                                                                                         
Adding localhost to LDAP object                                                                                                                                                                                                                                                  
Setting overview variables                                                                                                                                                                                                                                                       
Module: create_portal_entries                                                                                                                                                                                                                                                    
Reloading apache2 configuration (via systemctl): apache2.service.                                                                                                                                                                                                                
Registering schema /usr/share/univention-appcenter/apps/owncloud/owncloud.schema                                                                                                                                                                                                 
Object created: cn=owncloud,cn=ldapschema,cn=univention,dc=dev,dc=local                                                                                                                                                                                                          
                                                                                                                                                                                                                                                                                 
Object modified: cn=owncloud,cn=ldapschema,cn=univention,dc=dev,dc=local                                                                                                                                                                                                         
                                                                                                                                                                                                                                                                                 
Waiting for activation of the extension object owncloud:........OK                
Registering the container host owncl-05459398 for owncloud                            
Verifying Docker registry manifest for app image owncloud/appliance:latest         
Downloading app images                                              
Running command: docker-compose -p owncloud pull                                   
Pulling redis (webhippie/redis:latest)...                      
latest: Pulling from webhippie/redis                                               
Digest: sha256:3064a7fcdf0916936e87564cfaa0b09999c20518ab9450746849b824488087fa
Status: Downloaded newer image for webhippie/redis:latest
Pulling owncloud (owncloud/appliance:latest)...                
latest: Pulling from owncloud/appliance                       
Digest: sha256:8590bf9d90ac1c15db61d1fa3ccdfd5cd7acfdaacfb97f38e5e70ead60589edc
Status: Downloaded newer image for owncloud/appliance:latest                      
Pulling db (webhippie/mariadb:latest)...                   
latest: Pulling from webhippie/mariadb                           
Digest: sha256:4134bfcc7d0a72b33e593cf041933b7c28cbb29f38e8b57c12cfe5735167d3cc
Status: Downloaded newer image for webhippie/mariadb:latest    
Initializing app image                                                   
Preconfiguring container None          
Starting redis ...                     
Starting owncloud ...                  
Starting db ... 
 tarting db ... done. done                                                
Running command: journalctl -n 20 -o short /usr/bin/dockerd       
-- Logs begin at Fri 2019-03-01 13:58:51 CET, end at Wed 2019-03-06 14:57:46 CET. --
Going to remove ownCloud (10.1.0-2019-02-27)
[PRE_RM]                                        
Configuring 4.3/owncloud=10.1.0-2019-02-27
Removing localhost from LDAP object                                                                             
File: /usr/share/univention-portal/apps.json
File: /etc/univention/service.info/services/univention-appcenter.cfg                           
Multifile: /etc/apache2/sites-available/000-default.conf
Multifile: /etc/apache2/sites-available/default-ssl.conf                                              
Multifile: /etc/postgresql/9.6/main/pg_hba.conf
Module: create_portal_entries                                                                           
Reloading apache2 configuration (via systemctl): apache2.service.
Installing join script /var/cache/univention-appcenter/appcenter-test.software-univention.de/4.3/owncloud_20190226114121.uinst
univention-run-join-scripts: runs all join scripts existing on local computer.
copyright (c) 2001-2019 Univention GmbH, Germany                                                              
                                                         
Running pre-joinscripts hook(s):  done                                                                             
Running 01univention-ldap-server-init.inst skipped (already executed)
…
Running 51owncloud-uninstall.uinst done
Running post-joinscripts hook(s):  done
   ownCloud wurde erfolgreich entfernt.

   Um sicherzustellen, dass sie keinerlei Daten verlieren wurde ein Backup
   erstellt. Falls sie auf Probleme stoßen können sie es jederzeit
   wiederherstellen. Das Backup befindet sich unter
   /var/lib/univention-appcenter/backups/
sequence item 2: expected string, NoneType found
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/__init__.py", line 226, in call_with_namespace
    result = self.main(namespace)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install.py", line 84, in main
    return self.do_it(args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install_base.py", line 119, in do_it
    self._do_it(app, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_install.py", line 63, in _do_it
    ret = super(Install, self)._do_it(app, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/install.py", line 110, in _do_it
    if self._install_app(app, args):
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_install.py", line 57, in _install_app
    self._start_docker_image(app, hostdn, password, args)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/actions/docker_base.py", line 225, in _start_docker_image
    clogs = docker.logs()
  File "/usr/lib/pymodules/python2.7/univention/appcenter/docker.py", line 417, in logs
    return docker_logs(self.container, logger=self.logger)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/docker.py", line 223, in docker_logs
    ret, out = call_process2(args, logger=logger)
  File "/usr/lib/pymodules/python2.7/univention/appcenter/utils.py", line 207, in call_process2
    logger.info('Running command: {0}'.format(' '.join(cmd)))
TypeError: sequence item 2: expected string, NoneType found
Comment 1 Johannes Keiser univentionstaff 2019-03-22 15:57:13 CET
Version: 4.3-3 errata430 (Neustadt)

Internal server error during "appcenter/docker/progress".
Request: appcenter/docker/progress

Traceback (most recent call last):
  File "%PY2.7%/univention/management/console/base.py", line 253, in execute
    function.__func__(self, request, *args, **kwargs)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 318, in _response
    result = _multi_response(self, request)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 192, in _response
    return function(self, request)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 440, in _response
    return list(function(self, iterator, *nones))
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 286, in _fake_func
    yield function(self, *args)
  File "%PY2.7%/univention/management/console/modules/mixins.py", line 149, in progress
    ret = progress_obj.poll()
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 309, in _thread
    result = _multi_response(self, request)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 192, in _response
    return function(self, request)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 440, in _response
    return list(function(self, iterator, *nones))
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 286, in _fake_func
    yield function(self, *args)
  File "%PY2.7%/univention/management/console/modules/appcenter/__init__.py", line 431, in invoke_docker
    result['success'] = action.call(app=app, username=self.username, password=self.password, **kwargs)
  File "%PY2.7%/univention/appcenter/actions/__init__.py", line 220, in call
    return obj.call_with_namespace(namespace)
  File "%PY2.7%/univention/appcenter/actions/__init__.py", line 226, in call_with_namespace
    result = self.main(namespace)
  File "%PY2.7%/univention/appcenter/actions/install.py", line 73, in main
    return self.do_it(args)
  File "%PY2.7%/univention/appcenter/actions/install_base.py", line 109, in do_it
    self._do_it(app, args)
  File "%PY2.7%/univention/appcenter/actions/docker_install.py", line 63, in _do_it
    ret = super(Install, self)._do_it(app, args)
  File "%PY2.7%/univention/appcenter/actions/install.py", line 90, in _do_it
    if self._install_app(app, args):
  File "%PY2.7%/univention/appcenter/actions/docker_install.py", line 57, in _install_app
    self._start_docker_image(app, hostdn, password, args)
  File "%PY2.7%/univention/appcenter/actions/docker_base.py", line 225, in _start_docker_image
    clogs = docker.logs()
  File "%PY2.7%/univention/appcenter/docker.py", line 385, in logs
    return docker_logs(self.container, logger=self.logger)
  File "%PY2.7%/univention/appcenter/docker.py", line 186, in docker_logs
    ret, out = call_process2(args, logger=logger)
  File "%PY2.7%/univention/appcenter/utils.py", line 207, in call_process2
    logger.info('Running command: {0}'.format(' '.join(cmd)))
TypeError: sequence item 2: expected string, NoneType found

Role: domaincontroller_master
Comment 2 Felix Botner univentionstaff 2019-03-22 16:45:40 CET
this happens if cmd contains None

logger.info('Running command: {0}'.format(' '.join(cmd)))

this could mask real errors, we should fix it asap
Comment 3 Florian Best univentionstaff 2019-03-22 17:32:39 CET
Suggested patch: branch fbest/48881-graceful-logging
Comment 4 Johannes Keiser univentionstaff 2019-05-16 17:06:42 CEST
Reported again: Version: 4.3-3 errata477 (Neustadt)
Traceback: Same as Comment #1
Comment 5 Johannes Keiser univentionstaff 2019-05-28 11:43:20 CEST
Reported again: Version: 4.4-0 errata113 (Blumenthal)

Internal server error during "appcenter/docker/progress".
Request: appcenter/docker/progress

Traceback (most recent call last):
  File "%PY2.7%/univention/management/console/base.py", line 260, in execute
    function.__func__(self, request, *args, **kwargs)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 318, in _response
    result = _multi_response(self, request)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 192, in _response
    return function(self, request)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 440, in _response
    return list(function(self, iterator, *nones))
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 286, in _fake_func
    yield function(self, *args)
  File "%PY2.7%/univention/management/console/modules/mixins.py", line 149, in progress
    ret = progress_obj.poll()
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 309, in _thread
    result = _multi_response(self, request)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 192, in _response
    return function(self, request)
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 440, in _response
    return list(function(self, iterator, *nones))
  File "%PY2.7%/univention/management/console/modules/decorators.py", line 286, in _fake_func
    yield function(self, *args)
  File "%PY2.7%/univention/management/console/modules/appcenter/__init__.py", line 436, in invoke_docker
    result['success'] = action.call(app=app, username=self.username, password=self.password, **kwargs)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/actions/__init__.py", line 220, in call
    return obj.call_with_namespace(namespace)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/actions/__init__.py", line 226, in call_with_namespace
    result = self.main(namespace)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/actions/install.py", line 84, in main
    return self.do_it(args)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/actions/install_base.py", line 119, in do_it
    self._do_it(app, args)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/actions/docker_install.py", line 63, in _do_it
    ret = super(Install, self)._do_it(app, args)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/actions/install.py", line 110, in _do_it
    if self._install_app(app, args):
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/actions/docker_install.py", line 57, in _install_app
    self._start_docker_image(app, hostdn, password, args)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/actions/docker_base.py", line 225, in _start_docker_image
    clogs = docker.logs()
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/docker.py", line 372, in logs
    return docker_logs(self.container, logger=self.logger)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/docker.py", line 183, in docker_logs
    ret, out = call_process2(args, logger=logger)
  File "/usr/lib/python2.7/dist-packages/univention/appcenter/utils.py", line 207, in call_process2
    logger.info('Running command: {0}'.format(' '.join(cmd)))
TypeError: sequence item 2: expected string, NoneType found
Comment 6 Dirk Wiesenthal univentionstaff 2019-05-29 10:33:12 CEST
Just fixing the log message will not lower any error rate. If we handle None in the log message, None will raise an exception when passed to subprocess.

And we already have the traceback. From that it seems that the container is None. This is the real problem and should be handled properly.

The container probably did not really come up. This is DockerCouldNotStartContainer.

In fact, it seems that this errors occurs during the handling of this very exception. So instead of showing the user "Could not start container, here is the output of 'docker logs'", we present this traceback.

Maybe we should try/except around docker.logs?
Comment 7 Dirk Wiesenthal univentionstaff 2019-05-29 10:35:40 CEST
(We should _also_ fix the traceback when logging, leaving it there does not help either. It is just that we will then see the same traceback two lines later in call_process2())
Comment 8 Felix Botner univentionstaff 2019-06-04 09:56:13 CEST
c1ce4c3c236c4024bf33ba9dc4aeba951610729f univention-appcenter

as discussed, raise DockerCouldNotStartContainer is container is not set, fixed call_process2 cmd handling, get status information from init script in case Start.call fails.
Comment 9 Felix Botner univentionstaff 2019-06-04 11:26:32 CEST
(In reply to Felix Botner from comment #8)
> c1ce4c3c236c4024bf33ba9dc4aeba951610729f univention-appcenter
> 
> as discussed, raise DockerCouldNotStartContainer is container is not set,
> fixed call_process2 cmd handling, get status information from init script in
> case Start.call fails.

and 706b9f72386db20935de71c65666419ac496325e
Comment 10 Dirk Wiesenthal univentionstaff 2019-06-05 10:39:35 CEST
Works. But I fear that this may - in very rare cases - cause very strange bugs as we could now pass "None" as an argument to subprocess. As call_process2 is a key utility function, we should better not alter the cmd. Raised exceptions are ugly, but at least we can handle them.
Comment 11 Felix Botner univentionstaff 2019-06-05 11:13:08 CEST
(In reply to Dirk Wiesenthal from comment #10)
> Works. But I fear that this may - in very rare cases - cause very strange
> bugs as we could now pass "None" as an argument to subprocess. As
> call_process2 is a key utility function, we should better not alter the cmd.
> Raised exceptions are ugly, but at least we can handle them.

yep, convert cmd to strings for logging only
5a6eefe940a9ac4a4affc8d6b8623cb39345186b
Comment 12 Dirk Wiesenthal univentionstaff 2019-06-05 11:49:21 CEST
OK
Comment 13 Erik Damrose univentionstaff 2019-06-05 15:55:58 CEST
<http://errata.software-univention.de/ucs/4.4/141.html>