Uploaded image for project: 'MusicBrainz Search Server'
  1. MusicBrainz Search Server
  2. SEARCH-671

Live indexing errors on track update and fails to recover

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Normal Normal
    • None
    • None
    • Indexer
    • None

      This bug seems to have been triggered by edit #89485315 given it is related to both "Gentleman" and "Ram It Down" tracks.

      Failure to acknowledge two track update messages:

      2022-05-09T13:31:40.816523561Z 2022-05-09 13:31:40,816: Unable to perform action ack_message on message {'body': '{"id": 38320527, "_table": "track", "medium": 3597624, "recording": 27875266, "_operation": "update", "artist_credit": 2359426}', 'delivery_info': {u'consumer_tag': u'amq.ctag-z2J_ScbKZ7PFMqFyjtV3vg', u'redelivered': False, u'routing_key': u'update', u'delivery_tag': 822614, u'exchange': u'search'}, 'body_size': 127, 'frame_method': (60, 60), 'body_received': 127, 'ready': True, '_pending_chunks': [], 'properties': {}, 'channel': <amqp.channel.Channel object at 0x7f67c8180250>, 'frame_args': '\x00<\x00<\x1famq.ctag-z2J_ScbKZ7PFMqFyjtV3vg\x00\x00\x00\x00\x00\x0c\x8dV\x00\x06search\x06update'}. Exception encountered: Traceback (most recent call last):
      2022-05-09T13:31:40.816560536Z   File "sir/amqp/handler.py", line 85, in wrapper
      2022-05-09T13:31:40.816567291Z     return f(self, msg, *args, **kwargs)
      2022-05-09T13:31:40.816572203Z   File "sir/amqp/handler.py", line 228, in ack_message
      2022-05-09T13:31:40.816577752Z     self.channel.basic_ack(msg.delivery_tag)
      2022-05-09T13:31:40.816582998Z   File "/usr/local/lib/python2.7/site-packages/amqp/channel.py", line 1394, in basic_ack
      2022-05-09T13:31:40.816588455Z     spec.Basic.Ack, argsig, (delivery_tag, multiple),
      2022-05-09T13:31:40.816593568Z   File "/usr/local/lib/python2.7/site-packages/amqp/abstract_channel.py", line 59, in send_method
      2022-05-09T13:31:40.816598939Z     conn.frame_writer(1, self.channel_id, sig, args, content)
      2022-05-09T13:31:40.816603984Z   File "/usr/local/lib/python2.7/site-packages/amqp/method_framing.py", line 172, in write_frame
      2022-05-09T13:31:40.816609436Z     write(view[:offset])
      2022-05-09T13:31:40.816614384Z   File "/usr/local/lib/python2.7/site-packages/amqp/transport.py", line 284, in write
      2022-05-09T13:31:40.816620122Z     self._write(s)
      2022-05-09T13:31:40.816625026Z   File "/usr/local/lib/python2.7/socket.py", line 228, in meth
      2022-05-09T13:31:40.816630145Z     return getattr(self._sock,name)(*args)
      2022-05-09T13:31:40.816635152Z error: [Errno 32] Broken pipe
      2022-05-09T13:31:40.816640008Z 
      2022-05-09T13:31:40.903959782Z 2022-05-09 13:31:40,903: Unable to perform action ack_message on message {'body': '{"id": 38320534, "_table": "track", "medium": 3597624, "recording": 27875272, "_operation": "update", "artist_credit": 3188636}', 'delivery_info': {u'consumer_tag': u'amq.ctag-HoSS1huM5EkrKxfYHD2dAg', u'redelivered': True, u'routing_key': u'update', u'delivery_tag': 9, u'exchange': u'search'}, 'body_size': 127, 'frame_method': (60, 60), 'body_received': 127, 'ready': True, '_pending_chunks': [], 'properties': {}, 'channel': <amqp.channel.Channel object at 0x7f67c6359850>, 'frame_args': '\x00<\x00<\x1famq.ctag-HoSS1huM5EkrKxfYHD2dAg\x00\x00\x00\x00\x00\x00\x00\t\x01\x06search\x06update'}. Exception encountered: Traceback (most recent call last):
      2022-05-09T13:31:40.903994685Z   File "sir/amqp/handler.py", line 85, in wrapper
      2022-05-09T13:31:40.903998282Z     return f(self, msg, *args, **kwargs)
      2022-05-09T13:31:40.904001380Z   File "sir/amqp/handler.py", line 228, in ack_message
      2022-05-09T13:31:40.904004593Z     self.channel.basic_ack(msg.delivery_tag)
      2022-05-09T13:31:40.904007587Z   File "/usr/local/lib/python2.7/site-packages/amqp/channel.py", line 1394, in basic_ack
      2022-05-09T13:31:40.904010520Z     spec.Basic.Ack, argsig, (delivery_tag, multiple),
      2022-05-09T13:31:40.904013549Z   File "/usr/local/lib/python2.7/site-packages/amqp/abstract_channel.py", line 59, in send_method
      2022-05-09T13:31:40.904016627Z     conn.frame_writer(1, self.channel_id, sig, args, content)
      2022-05-09T13:31:40.904019451Z   File "/usr/local/lib/python2.7/site-packages/amqp/method_framing.py", line 172, in write_frame
      2022-05-09T13:31:40.904022742Z     write(view[:offset])
      2022-05-09T13:31:40.904025411Z   File "/usr/local/lib/python2.7/site-packages/amqp/transport.py", line 284, in write
      2022-05-09T13:31:40.904028282Z     self._write(s)
      2022-05-09T13:31:40.904031107Z   File "/usr/local/lib/python2.7/socket.py", line 228, in meth
      2022-05-09T13:31:40.904033813Z     return getattr(self._sock,name)(*args)
      2022-05-09T13:31:40.904036376Z error: [Errno 32] Broken pipe
      

      Followed with an indefinite failure to recover:

      2022-05-09T13:31:41.121236899Z 2022-05-09 13:31:41,121: Traceback (most recent call last):
      2022-05-09T13:31:41.121265255Z   File "sir/amqp/handler.py", line 458, in _watch_impl
      2022-05-09T13:31:41.121271554Z     handler.connection.drain_events(timeout)
      2022-05-09T13:31:41.121276386Z   File "/usr/local/lib/python2.7/site-packages/amqp/connection.py", line 505, in drain_events
      2022-05-09T13:31:41.121281298Z     while not self.blocking_read(timeout):
      2022-05-09T13:31:41.121285651Z   File "/usr/local/lib/python2.7/site-packages/amqp/connection.py", line 510, in blocking_read
      2022-05-09T13:31:41.121290158Z     frame = self.transport.read_frame()
      2022-05-09T13:31:41.121294391Z   File "/usr/local/lib/python2.7/site-packages/amqp/transport.py", line 252, in read_frame
      2022-05-09T13:31:41.121298774Z     frame_header = read(7, True)
      2022-05-09T13:31:41.121302916Z   File "/usr/local/lib/python2.7/site-packages/amqp/transport.py", line 446, in _read
      2022-05-09T13:31:41.121306886Z     raise IOError('Server unexpectedly closed connection')
      2022-05-09T13:31:41.121311356Z IOError: Server unexpectedly closed connection
      

      RabbitMQ log messages matching the initial failure:

      2022-05-09T13:31:40.007505740Z 2022-05-09 13:31:39.639 [info] <0.29106.203> supervisor: {<0.29106.203>,rabbit_channel_sup_sup}, errorContext: shutdown_error, reason: shutdown, offender: [{nb_children,1},{id,channel_sup},{mfargs,{rabbit_channel_sup,start_link,[]}},{restart_type,temporary},{shutdown,infinity},{child_type,supervisor}]
      2022-05-09T13:31:40.007511000Z 2022-05-09 13:31:39.640 [error] <0.29106.203> Supervisor {<0.29106.203>,rabbit_channel_sup_sup} had child channel_sup started with rabbit_channel_sup:start_link() at undefined exit with reason shutdown in context shutdown_error
      

            Unassigned Unassigned
            yvanzo yvanzo
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:

                Version Package