Autophone - lock released too many times while shutting down pulse listener

RESOLVED FIXED

Status

RESOLVED FIXED
2 years ago
2 years ago

People

(Reporter: bc, Assigned: bc)

Tracking

(Blocks: 1 bug)

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

(Assignee)

Description

2 years ago
During testing I ran into the following after a restart followed some time later by a shutdown

2017-05-07 16:54:50,627 console INFO Autophone started.
Exception in thread PulseMonitorThread:
Traceback (most recent call last):
  File "/usr/lib64/python2.7/threading.py", line 804, in __bootstrap_inner
    self.run()
  File "/usr/lib64/python2.7/threading.py", line 757, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/mozilla/projects/autophone/src/bclary-autophone/autophonepulsemonitor.py", line 258, in listen
    self.shared_lock.release()
ValueError: semaphore or lock released too many times

this occurs in the finally clause as the listen method is exited.
(Assignee)

Comment 1

2 years ago
This was caused by an exception cause by code under development in the handle_build method

Traceback (most recent call last):
  File "/mozilla/projects/autophone/src/bclary-autophone/autophonepulsemonitor.py", line 232, in listen
    connection.drain_events(timeout=self.timeout)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/kombu/connection.py", line 301, in drain_events
    return self.transport.drain_events(self.connection, **kwargs)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/kombu/transport/pyamqp.py", line 103, in drain_events
    return connection.drain_events(**kwargs)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/amqp/connection.py", line 464, in drain_events
    return self.blocking_read(timeout)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/amqp/connection.py", line 469, in blocking_read
    return self.on_inbound_frame(frame)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/amqp/method_framing.py", line 88, in on_frame
    callback(channel, msg.frame_method, msg.frame_args, msg)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/amqp/connection.py", line 473, in on_inbound_method
    method_sig, payload, content,
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/amqp/abstract_channel.py", line 142, in dispatch_method
    listener(*args)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/amqp/channel.py", line 1613, in _on_basic_deliver
    fun(msg)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/kombu/messaging.py", line 623, in _receive_callback
    return on_m(message) if on_m else self.receive(decoded, message)
  File "/mozilla/projects/.virtualenvs/autophone/lib/python2.7/site-packages/kombu/messaging.py", line 589, in receive
    [callback(body, message) for callback in callbacks]
  File "/mozilla/projects/autophone/src/bclary-autophone/autophonepulsemonitor.py", line 275, in handle_message
    self.handle_build(data, message)
  File "/mozilla/projects/autophone/src/bclary-autophone/autophonepulsemonitor.py", line 339, in handle_build
    build_properties['appname'].lower() != 'geckoviewactivity':
KeyError: 'appname'

This may be invalid though it does seem to me that the lock should have been reacquired before the outer finally clause.
(Assignee)

Comment 2

2 years ago
Created attachment 8865415 [details] [diff] [review]
bug-1362899-LOGGER.patch

At least part of the problem and maybe the full problem was the failure to change all instances of LOGGER to logger in 1304063 which raised an exception prior to the reacquiring of the shared lock. This only shows up when verbose logging is enabled which isn't the case in production fortunately.
Attachment #8865415 - Flags: review?(jmaher)
(Assignee)

Updated

2 years ago
Assignee: nobody → bob
Status: NEW → ASSIGNED
Comment on attachment 8865415 [details] [diff] [review]
bug-1362899-LOGGER.patch

Review of attachment 8865415 [details] [diff] [review]:
-----------------------------------------------------------------

easy one!
Attachment #8865415 - Flags: review?(jmaher) → review+
(Assignee)

Comment 4

2 years ago
https://github.com/mozilla/autophone/commit/c3e4974014cd6a928baf6614306a73a807917f52
Blocks: 1157427
Status: ASSIGNED → RESOLVED
Last Resolved: 2 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.