PlainBox (Toolkit)

Python script crash when getting jobs list in canonical-certification-server

Bug #1432055 reported by Rod Smith
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
PlainBox (Toolkit)
Invalid
Low
Unassigned

Bug Description

1. Launch canonical-certification-server
2. Choose to run a Server-full-14.04 test

Among the information displayed appears the following Python trace dump (plus some context):

ID: 2013.com.canonical.certification::package
Category: 2013.com.canonical.plainbox::uncategorised
(Command output hidden)
Outcome: job passed
-----------------------------------[ device ]-----------------------------------
ID: 2013.com.canonical.certification::device
Category: 2013.com.canonical.plainbox::uncategorised
(Command output hidden)
--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 293, in _instantiate_templates
    new_unit.validate()
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 385, in validate
    self, **validation_kwargs)
  File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 107, in validate
    super().validate(job, strict, deprecated)
  File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 85, in validate
    super().validate(unit, strict, deprecated)
  File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 67, in validate
    raise ValidationError(field, Problem.wrong)
plainbox.impl.validation.ValidationError: Problem with field command: wrong

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.4/logging/__init__.py", line 964, in emit
    msg = self.format(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 814, in format
    return fmt.format(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 551, in format
    record.message = record.getMessage()
  File "/usr/lib/python3.4/logging/__init__.py", line 314, in getMessage
    msg = msg % self.args
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 187, in __str__
    return self.summary
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 217, in summary
    return self.get_record_value('summary', self.partial_id)
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 209, in partial_id
    return self.get_record_value('id', self.get_record_value('name'))
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/unit.py", line 594, in get_record_value
    value = string.Formatter().vformat(value, (), self.parameters)
  File "/usr/lib/python3.4/string.py", line 168, in vformat
    result = self._vformat(format_string, args, kwargs, used_args, 2)
  File "/usr/lib/python3.4/string.py", line 190, in _vformat
    obj, arg_used = self.get_field(field_name, args, kwargs)
  File "/usr/lib/python3.4/string.py", line 253, in get_field
    obj = self.get_value(first, args, kwargs)
  File "/usr/lib/python3.4/string.py", line 210, in get_value
    return kwargs[key]
KeyError: 'name'
Call stack:
  File "/usr/bin/checkbox-launcher", line 9, in <module>
    load_entry_point('checkbox-ng==0.17', 'console_scripts', 'checkbox-launcher')()
  File "/usr/lib/python3/dist-packages/checkbox_ng/main.py", line 62, in launcher
    raise SystemExit(CheckboxLauncherTool().main(argv))
  File "/usr/lib/python3/dist-packages/plainbox/impl/clitools.py", line 324, in main
    return self.dispatch_and_catch_exceptions(ns)
  File "/usr/lib/python3/dist-packages/plainbox/impl/clitools.py", line 560, in dispatch_and_catch_exceptions
    return self.dispatch_command(ns)
  File "/usr/lib/python3/dist-packages/plainbox/impl/clitools.py", line 556, in dispatch_command
    return ns.command.invoked(ns)
  File "/usr/lib/python3/dist-packages/checkbox_ng/commands/launcher.py", line 87, in invoked
    ).run()
  File "/usr/lib/python3/dist-packages/checkbox_ng/commands/newcli.py", line 114, in run
    return self.do_normal_sequence()
  File "/usr/lib/python3/dist-packages/checkbox_ng/commands/newcli.py", line 155, in do_normal_sequence
    self.run_all_selected_jobs()
  File "/usr/lib/python3/dist-packages/plainbox/impl/commands/inv_run.py", line 706, in run_all_selected_jobs
    self.run_single_job(job)
  File "/usr/lib/python3/dist-packages/plainbox/impl/commands/inv_run.py", line 710, in run_single_job
    self.run_single_job_with_ui(job, self.get_ui_for_job(job))
  File "/usr/lib/python3/dist-packages/plainbox/impl/commands/inv_run.py", line 740, in run_single_job_with_ui
    self.state.update_job_result(job, job_result)
  File "/usr/lib/python3/dist-packages/plainbox/impl/session/state.py", line 845, in update_job_result
    job.controller.observe_result(self, job, result)
  File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 246, in observe_result
    self._process_resource_result(session_state, job, result)
  File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 256, in _process_resource_result
    self._instantiate_templates(session_state, job, result)
  File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 297, in _instantiate_templates
    new_unit, exc)
Unable to print the message and arguments - possible formatting error.
Use the traceback above to help find the error.
--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 293, in _instantiate_templates
    new_unit.validate()
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 385, in validate
    self, **validation_kwargs)
  File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 107, in validate
    super().validate(job, strict, deprecated)
  File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 85, in validate
    super().validate(unit, strict, deprecated)
  File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 67, in validate
    raise ValidationError(field, Problem.wrong)
plainbox.impl.validation.ValidationError: Problem with field command: wrong

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.4/logging/__init__.py", line 964, in emit
    msg = self.format(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 814, in format
    return fmt.format(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 551, in format
    record.message = record.getMessage()
  File "/usr/lib/python3.4/logging/__init__.py", line 314, in getMessage
    msg = msg % self.args
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 187, in __str__
    return self.summary
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 217, in summary
    return self.get_record_value('summary', self.partial_id)
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 209, in partial_id
    return self.get_record_value('id', self.get_record_value('name'))
  File "/usr/lib/python3/dist-packages/plainbox/impl/unit/unit.py", line 594, in get_record_value
    value = string.Formatter().vformat(value, (), self.parameters)
  File "/usr/lib/python3.4/string.py", line 168, in vformat
    result = self._vformat(format_string, args, kwargs, used_args, 2)
  File "/usr/lib/python3.4/string.py", line 190, in _vformat
    obj, arg_used = self.get_field(field_name, args, kwargs)
  File "/usr/lib/python3.4/string.py", line 253, in get_field
    obj = self.get_value(first, args, kwargs)
  File "/usr/lib/python3.4/string.py", line 210, in get_value
    return kwargs[key]
KeyError: 'name'
Call stack:
  File "/usr/bin/checkbox-launcher", line 9, in <module>
    load_entry_point('checkbox-ng==0.17', 'console_scripts', 'checkbox-launcher')()
  File "/usr/lib/python3/dist-packages/checkbox_ng/main.py", line 62, in launcher
    raise SystemExit(CheckboxLauncherTool().main(argv))
  File "/usr/lib/python3/dist-packages/plainbox/impl/clitools.py", line 324, in main
    return self.dispatch_and_catch_exceptions(ns)
  File "/usr/lib/python3/dist-packages/plainbox/impl/clitools.py", line 560, in dispatch_and_catch_exceptions
    return self.dispatch_command(ns)
  File "/usr/lib/python3/dist-packages/plainbox/impl/clitools.py", line 556, in dispatch_command
    return ns.command.invoked(ns)
  File "/usr/lib/python3/dist-packages/checkbox_ng/commands/launcher.py", line 87, in invoked
    ).run()
  File "/usr/lib/python3/dist-packages/checkbox_ng/commands/newcli.py", line 114, in run
    return self.do_normal_sequence()
  File "/usr/lib/python3/dist-packages/checkbox_ng/commands/newcli.py", line 155, in do_normal_sequence
    self.run_all_selected_jobs()
  File "/usr/lib/python3/dist-packages/plainbox/impl/commands/inv_run.py", line 706, in run_all_selected_jobs
    self.run_single_job(job)
  File "/usr/lib/python3/dist-packages/plainbox/impl/commands/inv_run.py", line 710, in run_single_job
    self.run_single_job_with_ui(job, self.get_ui_for_job(job))
  File "/usr/lib/python3/dist-packages/plainbox/impl/commands/inv_run.py", line 740, in run_single_job_with_ui
    self.state.update_job_result(job, job_result)
  File "/usr/lib/python3/dist-packages/plainbox/impl/session/state.py", line 845, in update_job_result
    job.controller.observe_result(self, job, result)
  File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 246, in observe_result
    self._process_resource_result(session_state, job, result)
  File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 256, in _process_resource_result
    self._instantiate_templates(session_state, job, result)
  File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 297, in _instantiate_templates
    new_unit, exc)
Unable to print the message and arguments - possible formatting error.
Use the traceback above to help find the error.
Outcome: job passed
-------------------------------[ optical_drive ]--------------------------------
ID: 2013.com.canonical.certification::optical_drive
Category: 2013.com.canonical.plainbox::uncategorised
(Command output hidden)
Outcome: job passed

Thereafter, tests seem to run normally.

I've seen this on many computers recently; AFAIK it's always reproducible.

More requested data:

$ apt-cache policy plainbox
plainbox:
  Installed: (none)
  Candidate: 0.20~ppa~ubuntu14.04.1
  Version table:
     0.20~ppa~ubuntu14.04.1 0
        500 http://ppa.launchpad.net/hardware-certification/public/ubuntu/ trusty/main amd64 Packages
     0.5.3-2 0
        500 http://us.archive.ubuntu.com//ubuntu/ trusty/universe amd64 Packages

$ apt-cache policy checkbox
checkbox:
  Installed: (none)
  Candidate: 0.17.6-0ubuntu6
  Version table:
     0.17.6-0ubuntu6 0
        500 http://us.archive.ubuntu.com//ubuntu/ trusty/universe amd64 Packages

$ plainbox dev list provider
provider '2013.com.canonical.certification:certification-server'
provider '2013.com.canonical.certification:checkbox'
provider '2013.com.canonical.certification:plainbox-resources'

Revision history for this message
Rod Smith (rodsmith) wrote :
Revision history for this message
Zygmunt Krynicki (zyga) wrote : Re: [Bug 1432055] [NEW] Python script crash when getting jobs list in canonical-certification-server
Download full text (12.7 KiB)

Hey, thanks for the report.

This *seems* like a duplicate of another report that Pierre has filed.
Notice that it's just the logging that crashes and execution is not
interrupted. Still, it's annoying so I think we need to handle it
better.

Best regards
ZK

On Fri, Mar 13, 2015 at 10:18 PM, Roderick Smith
<email address hidden> wrote:
> Public bug reported:
>
> 1. Launch canonical-certification-server
> 2. Choose to run a Server-full-14.04 test
>
> Among the information displayed appears the following Python trace dump
> (plus some context):
>
> ID: 2013.com.canonical.certification::package
> Category: 2013.com.canonical.plainbox::uncategorised
> (Command output hidden)
> Outcome: job passed
> -----------------------------------[ device ]-----------------------------------
> ID: 2013.com.canonical.certification::device
> Category: 2013.com.canonical.plainbox::uncategorised
> (Command output hidden)
> --- Logging error ---
> Traceback (most recent call last):
> File "/usr/lib/python3/dist-packages/plainbox/impl/ctrl.py", line 293, in _instantiate_templates
> new_unit.validate()
> File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 385, in validate
> self, **validation_kwargs)
> File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
> return func(*args, **kwargs)
> File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 107, in validate
> super().validate(job, strict, deprecated)
> File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
> return func(*args, **kwargs)
> File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 85, in validate
> super().validate(unit, strict, deprecated)
> File "/usr/lib/python3/dist-packages/plainbox/impl/__init__.py", line 179, in wrapper
> return func(*args, **kwargs)
> File "/usr/lib/python3/dist-packages/plainbox/impl/unit/_legacy.py", line 67, in validate
> raise ValidationError(field, Problem.wrong)
> plainbox.impl.validation.ValidationError: Problem with field command: wrong
>
> During handling of the above exception, another exception occurred:
>
> Traceback (most recent call last):
> File "/usr/lib/python3.4/logging/__init__.py", line 964, in emit
> msg = self.format(record)
> File "/usr/lib/python3.4/logging/__init__.py", line 814, in format
> return fmt.format(record)
> File "/usr/lib/python3.4/logging/__init__.py", line 551, in format
> record.message = record.getMessage()
> File "/usr/lib/python3.4/logging/__init__.py", line 314, in getMessage
> msg = msg % self.args
> File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 187, in __str__
> return self.summary
> File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 217, in summary
> return self.get_record_value('summary', self.partial_id)
> File "/usr/lib/python3/dist-packages/plainbox/impl/unit/job.py", line 209, in partial_id
> return self.get_record_value('id', self.get_record_value('name'))
> File "/usr/lib/python3/dist-packages/plainbox/impl/unit/unit.py", line 594, in get_record_value
> value = stri...

Revision history for this message
Zygmunt Krynicki (zyga) wrote :

I think there's a duplicate of this issue out there. When we validate a job and it doesn't pass (for any reason) we try to print it and say "this job here doesn't validate". When we try to print it and the problem is related to missing job ID then we get a crash in logging. It's not fatal bug looks very bad.

affects: checkbox → plainbox
Changed in plainbox:
status: New → Confirmed
importance: Undecided → Low
Sylvain Pineau (sylvain-pineau)
Changed in plainbox:
status: Confirmed → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.