Backtrace in juju debug-log when destroying a service

Bug #886232 reported by Thomas Herve
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
pyjuju
Triaged
Low
Unassigned

Bug Description

Seen while testing a charm:

$ juju destroy-service landscape

2011-11-04 12:56:48,236 unit:landscape/3: unit.lifecycle DEBUG: services changed old:[<ServiceRelationState name:website role:client id:relation-0000000011>] new:[]
2011-11-04 12:56:48,237 unit:landscape/3: unit.lifecycle DEBUG: processing relations changed
2011-11-04 12:56:48,237 unit:landscape/3: unit.relation.watch DEBUG: relation watcher stop
2011-11-04 12:56:48,237 unit:landscape/3: hook.scheduler DEBUG: stop
2011-11-04 12:56:48,237 unit:landscape/3: unit.relation.lifecycle DEBUG: stopped relation:website lifecycle
2011-11-04 12:56:48,239 unit:landscape/3: statemachine DEBUG: relationworkflowstate: transition state (up -> departed)
2011-11-04 12:56:48,240 unit:landscape/3: statemachine DEBUG: relationworkflowstate: transition depart (up -> departed) {}
2011-11-04 12:56:48,240 unit:landscape/3: statemachine DEBUG: relationworkflowstate: execute action do_depart
2011-11-04 12:56:48,240 unit:landscape/3: unit.relation.watch DEBUG: relation watcher stop
2011-11-04 12:56:48,241 unit:apache2/2: unit.lifecycle DEBUG: services changed old:[<ServiceRelationState name:website role:server id:relation-0000000011>] new:[]
2011-11-04 12:56:48,241 unit:landscape/3: hook.scheduler DEBUG: stop
2011-11-04 12:56:48,241 unit:landscape/3: unit.relation.lifecycle DEBUG: stopped relation:website lifecycle
2011-11-04 12:56:48,241 unit:apache2/2: unit.lifecycle DEBUG: processing relations changed
2011-11-04 12:56:48,241 unit:apache2/2: unit.relation.watch DEBUG: relation watcher stop
2011-11-04 12:56:48,241 unit:landscape/3: unit.relation.lifecycle DEBUG: depart relation lifecycle
2011-11-04 12:56:48,242 unit:apache2/2: hook.scheduler DEBUG: stop
2011-11-04 12:56:48,241 unit:landscape/3: unit.relation.lifecycle DEBUG: Executing hook website-relation-broken
2011-11-04 12:56:48,241 unit:landscape/3: hook.executor DEBUG: Running hook: /var/lib/juju/units/landscape-3/charm/hooks/website-relation-broken
2011-11-04 12:56:48,242 unit:apache2/2: unit.relation.lifecycle DEBUG: stopped relation:website lifecycle
2011-11-04 12:56:48,243 unit:apache2/2: statemachine DEBUG: relationworkflowstate: transition state (up -> departed)
2011-11-04 12:56:48,244 unit:apache2/2: statemachine DEBUG: relationworkflowstate: transition depart (up -> departed) {}
2011-11-04 12:56:48,245 unit:apache2/2: statemachine DEBUG: relationworkflowstate: execute action do_depart
2011-11-04 12:56:48,245 unit:apache2/2: unit.relation.watch DEBUG: relation watcher stop
2011-11-04 12:56:48,245 unit:apache2/2: hook.scheduler DEBUG: stop
2011-11-04 12:56:48,248 unit:landscape/3: hook.output DEBUG: hook website-relation-broken exited, exit code 0.
2011-11-04 12:56:48,246 unit:apache2/2: unit.relation.lifecycle DEBUG: stopped relation:website lifecycle
2011-11-04 12:56:48,247 unit:apache2/2: unit.relation.lifecycle DEBUG: depart relation lifecycle
2011-11-04 12:56:48,247 unit:apache2/2: unit.relation.lifecycle DEBUG: Executing hook website-relation-broken
2011-11-04 12:56:48,247 unit:apache2/2: hook.executor DEBUG: Running hook: /var/lib/juju/units/apache2-2/charm/hooks/website-relation-broken
2011-11-04 12:56:48,251 unit:apache2/2: hook.output DEBUG: hook website-relation-broken exited, exit code 0.
2011-11-04 12:56:48,270 Machine:0: juju.agents.machine DEBUG: Units changed old:set(['apache2/2', 'landscape/3']) new:set(['apache2/2'])
2011-11-04 12:56:48,271 Machine:0: juju.agents.machine DEBUG: Stopping service unit: landscape/3 ...
2011-11-04 12:56:48,271 Machine:0: juju.agents.machine INFO: Stopping service unit landscape/3...
2011-11-04 12:56:48,271 Machine:0: unit.deploy DEBUG: Destroying container...
2011-11-04 12:56:48,282 unit:landscape/3: hook.executor DEBUG: Hook complete: /var/lib/juju/units/landscape-3/charm/hooks/website-relation-broken
2011-11-04 12:56:48,294 unit:apache2/2: hook.executor DEBUG: Hook complete: /var/lib/juju/units/apache2-2/charm/hooks/website-relation-broken
2011-11-04 12:56:48,306 unit:apache2/2: statemachine DEBUG: relationworkflowstate: transition complete depart (state departed) {}
2011-11-04 12:56:48,308 unit:landscape/3: twisted ERROR: Unhandled error in Deferred:
2011-11-04 12:56:48,309 unit:landscape/3: twisted ERROR: Unhandled Error
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 388, in errback
    self._startRunCallbacks(fail)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 455, in _startRunCallbacks
    self._runCallbacks()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 542, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1076, in gotResult
    _inlineCallbacks(r, g, deferred)
--- <exception caught here> ---
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/state/base.py", line 138, in __topology_changed
    yield watch_topology_function(self._old_topology, new_topology)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/unit/lifecycle.py", line 229, in _on_service_relation_changes
    yield self._process_service_changes(old_relations, new_relations)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/unit/lifecycle.py", line 258, in _process_service_changes
    yield workflow.transition_state("departed")
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/lib/statemachine.py", line 132, in transition_state
    result = yield self.fire_transition(transition.transition_id)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/lib/statemachine.py", line 190, in fire_transition
    yield self.set_state(transition.destination, **state_variables)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/lib/statemachine.py", line 233, in set_state
    yield self._store(dict(state=state, state_variables=variables))
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/unit/workflow.py", line 239, in _store
    yield retry_change(self._client, self.zk_state_path, update_state)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/txzookeeper/utils.py", line 54, in retry_change
    new_content = yield change_function(content, stat)
  File "/usr/lib/python2.7/dist-packages/juju/unit/workflow.py", line 231, in update_state
    unit_data = yaml.load(content)
  File "/usr/lib/python2.7/dist-packages/yaml/__init__.py", line 69, in load
    loader = Loader(stream)
  File "/usr/lib/python2.7/dist-packages/yaml/loader.py", line 34, in __init__
    Reader.__init__(self, stream)
  File "/usr/lib/python2.7/dist-packages/yaml/reader.py", line 85, in __init__
    self.determine_encoding()
  File "/usr/lib/python2.7/dist-packages/yaml/reader.py", line 124, in determine_encoding
    self.update_raw()
  File "/usr/lib/python2.7/dist-packages/yaml/reader.py", line 178, in update_raw
    data = self.stream.read(size)
exceptions.AttributeError: 'NoneType' object has no attribute 'read'

2011-11-04 12:56:48,312 unit:landscape/3: juju.agents.unit DEBUG: Configuration Changed
2011-11-04 12:56:48,314 unit:landscape/3: statemachine DEBUG: unitworkflowstate: transition reconfigure (started -> started) {}
2011-11-04 12:56:48,314 unit:landscape/3: statemachine DEBUG: unitworkflowstate: execute action do_reconfigure
2011-11-04 12:56:48,315 unit:landscape/3: hook.executor INFO: Hook does not exist, skipping /var/lib/juju/units/landscape-3/charm/hooks/config-changed
2011-11-04 12:56:48,316 unit:landscape/3: unit.lifecycle DEBUG: configured unit
2011-11-04 12:56:48,333 unit:landscape/3: twisted ERROR: Unhandled error in Deferred:
2011-11-04 12:56:48,334 unit:landscape/3: twisted ERROR: Unhandled Error
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 388, in errback
    self._startRunCallbacks(fail)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 455, in _startRunCallbacks
    self._runCallbacks()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 542, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1076, in gotResult
    _inlineCallbacks(r, g, deferred)
--- <exception caught here> ---
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/state/service.py", line 494, in watcher
    yield callback(change_event)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/agents/unit.py", line 203, in cb_watch_config_changed
    yield self.workflow.fire_transition("reconfigure")
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/lib/statemachine.py", line 190, in fire_transition
    yield self.set_state(transition.destination, **state_variables)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/lib/statemachine.py", line 233, in set_state
    yield self._store(dict(state=state, state_variables=variables))
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/juju/unit/workflow.py", line 239, in _store
    yield retry_change(self._client, self.zk_state_path, update_state)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1018, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/dist-packages/twisted/python/failure.py", line 350, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/dist-packages/txzookeeper/utils.py", line 54, in retry_change
    new_content = yield change_function(content, stat)
  File "/usr/lib/python2.7/dist-packages/juju/unit/workflow.py", line 231, in update_state
    unit_data = yaml.load(content)
  File "/usr/lib/python2.7/dist-packages/yaml/__init__.py", line 69, in load
    loader = Loader(stream)
  File "/usr/lib/python2.7/dist-packages/yaml/loader.py", line 34, in __init__
    Reader.__init__(self, stream)
  File "/usr/lib/python2.7/dist-packages/yaml/reader.py", line 85, in __init__
    self.determine_encoding()
  File "/usr/lib/python2.7/dist-packages/yaml/reader.py", line 124, in determine_encoding
    self.update_raw()
  File "/usr/lib/python2.7/dist-packages/yaml/reader.py", line 178, in update_raw
    data = self.stream.read(size)
exceptions.AttributeError: 'NoneType' object has no attribute 'read'

2011-11-04 12:56:49,390 Machine:0: unit.deploy INFO: Destroyed container for landscape/

Revision history for this message
Kapil Thangavelu (hazmat) wrote :

Thanks for reporting. Effectively the unit data tree is being destroyed from the cli to trigger the unit destruction, which in turn causes the machine agent to kill the unit, but the unit agent is still executing hooks and tries to update the tree with the state post the hook run, except there isn't anything to update at that point.

Changed in juju:
status: New → In Progress
assignee: nobody → Kapil Thangavelu (hazmat)
milestone: none → florence
Revision history for this message
Kapil Thangavelu (hazmat) wrote :

Effectively this is harmless, its a communication mismatch on termination. I'm going to update the destroy-service/remote-unit to not actually remove the unit state, so this final communication/state recording b4 termination can be achieved, and leave the unit state cleanup for a zk state garbage collector.

Revision history for this message
Gustavo Niemeyer (niemeyer) wrote :

For the record, reproducing the comment from the MP:

----

FWIW, I agree with Jim on this one in that it's an API change. The fact that you're not removing nodes from the tree as was done before is definitely a change in the way that things are stored, and will impact multiple areas of the code base and should be sent to the list for general awareness.

How is this handling status, for instance?

The description also feels naively optimistic in the sense that it's just saying "leave to GC", without further explaining what that really means.

Changed in juju:
status: In Progress → Confirmed
assignee: Kapil Thangavelu (hazmat) → nobody
Changed in juju:
milestone: florence → galapagos
Revision history for this message
Clint Byrum (clint-fewbar) wrote :

API changes would not be appropriate for galapagos's intended release goals, dropping from milestone.

Changed in juju:
milestone: galapagos → none
importance: Undecided → Low
Curtis Hovey (sinzui)
Changed in juju:
status: Confirmed → Triaged
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

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