Changes between Initial Version and Version 1 of Ticket #5379, comment 7


Ignore:
Timestamp:
Feb 10, 2017, 6:16:02 AM (9 years ago)
Author:
Jorge

Legend:

Unmodified
Added
Removed
Modified

  • Ticket #5379, comment 7

    initial v1  
    1 admin comes to you asking for the reason ..
     1(removed former long trace)
    22
    3 DEBUG output uploading mp3 via lazyserver.sh (selective output .. solution below)
    4 {{{
    5 0:03:42.413651788  8461 0x81d844f0 WARN            audioencoder gstaudioencoder.c:985:gst_audio_encoder_finish_frame:<enc> Can't copy metadata because input buffer disapp
    6 eared 
    7 ...
    8 0:04:15.901886228  8461 0x81d84980 WARN                 basesrc gstbasesrc.c:2400:gst_base_src_update_length:<filesrc> processing at or past EOS
    9 ...
    10 2017-02-10 05:19:12,316 INFO    [mediagoblin.media_types.audio.transcoders] 100% done...                                                                                 
    11 2017-02-10 05:19:12,317 DEBUG   [mediagoblin.media_types.audio.transcoders] <flags GST_MESSAGE_ELEMENT of type Gst.MessageType>                                           
    12 2017-02-10 05:19:12,349 INFO    [mediagoblin.media_types.audio.transcoders] 100% done...
    13 2017-02-10 05:19:12,351 DEBUG   [mediagoblin.media_types.audio.transcoders] <flags GST_MESSAGE_EOS of type Gst.MessageType>
    14 2017-02-10 05:19:12,352 INFO    [mediagoblin.media_types.audio.transcoders] Done
    15 ...
    16 2017-02-10 05:19:12,503 INFO    [mediagoblin.media_types.audio.transcoders] Quitting MainLoop gracefully...
    17 ...
    18 2017-02-10 05:19:12,602 DEBUG   [mediagoblin.media_types.audio.processing] Saving medium...
    19 /srv/mediagoblin.latest/lib/python2.7/site-packages/SQLAlchemy-1.1.5-py2.7-linux-i686.egg/sqlalchemy/sql/sqltypes.py:219: SAWarning: Unicode type received non-unicode bin
    20 d param value 'webm_audio'. (this warning may be suppressed after 10 occurrences)
    21 2017-02-10 05:19:12,866 INFO    [mediagoblin.media_types.audio.processing] Creating OGG source for spectrogram
    22 2017-02-10 05:19:12,867 INFO    [mediagoblin.media_types.audio.transcoders] Transcoding /media/public/mgoblin/media/queue/media_entries/555c6ffa-7239-4022-ab5c-1f6105a61a
    23 e8/20150706-focuseuropan-w2575.mp3 into /srv/mediagoblin/user_dev/media/workbench/tmpgY2Avv/20150706..ogg
    24 ...
    25 0:04:17.542465655  8461 0x81ee03c0 INFO                 filesrc gstfilesrc.c:465:gst_file_src_start:<filesrc> opening file /media/public/mgoblin/media/queue/media_entries
    26 /555c6ffa-7239-4022-ab5c-1f6105a61ae8..mp3
    27 0:04:17.542644098  8461 0x81ee03c0 WARN                 basesrc gstbasesrc.c:3491:gst_base_src_start_complete:<filesrc> pad not activated yet
    28 0:04:17.542771208  8461 0x81ee03c0 INFO                 filesrc gstfilesrc.c:465:gst_file_src_start:<filesrc> opening file /media/public/mgoblin/media/queue/media_entries
    29 /555c6ffa-7239-4022-ab5c-1f6105a61ae8.mp3
    30 0:04:17.542914940  8461 0x81ee03c0 INFO                    task gsttask.c:456:gst_task_set_lock: setting stream lock 0xace7c8bc on task 0xace8ca48
    31 0
    32 ...
    33 2017-02-10 05:19:13,221 DEBUG   [mediagoblin.media_types.audio.transcoders] <flags GST_MESSAGE_TAG of type Gst.MessageType>
    34 0:04:17.754148124  8461 0x81d844f0 FIXME               basesink gstbasesink.c:3077:gst_base_sink_default_event:<sink> stream-start event without group-id. Consider implem
    35 enting group-id handling in the upstream elements
    36 2017-02-10 05:19:13,222 DEBUG   [mediagoblin.media_types.audio.transcoders] <flags GST_MESSAGE_STREAM_START of type Gst.MessageType>
    37                          
    38 ...
    39 0:04:17.840180701  8461 0x81d844f0 INFO                oggdemux gstoggstream.c:2678:gst_ogg_stream_setup_map_from_caps_headers: Found headers on caps, using those to determine type
    40 0:04:17.840372344  8461 0x81d844f0 WARN            audioencoder gstaudioencoder.c:985:gst_audio_encoder_finish_frame:<enc> Can't copy metadata because input buffer disappeared
    41 0:04:17.758349604  8461 0x81d85030 INFO            audiodecoder gstaudiodecoder.c:2320:gst_audio_decoder_sink_eventfunc:<mad1> upstream stream tags: taglist, has-crc=(boo
    42 lean)false, channel-mode=(string)joint-stereo, audio-codec=(string)"MPEG-1\ Layer\ 3\ \(MP3\)", nominal-bitrate=(uint)128000, minimum-bitrate=(uint)127706, maximum-bitrat
    43 e=(uint)128012, bitrate=(uint)127986;                                                                                        ...
    44 0:04:15.901886228  8461 0x81d84980 WARN                 basesrc gstbasesrc.c:2400:gst_base_src_update_length:<filesrc> processing at or past EOS                         
    45 2017-02-10 05:19:38,035 INFO    [mediagoblin.media_types.audio.transcoders] 87% done...                                                                                   
    46 0:04:45.789429989  8461 0x81d85030 WARN                 basesrc gstbasesrc.c:2400:gst_base_src_update_length:<filesrc> processing at or past EOS                         
    47 2017-02-10 05:19:13,221 DEBUG   [mediagoblin.media_types.audio.transcoders] <flags GST_MESSAGE_TAG of type Gst.MessageType>
    48 0:04:17.754148124  8461 0x81d844f0 FIXME               basesink gstbasesink.c:3077:gst_base_sink_default_event:<sink> stream-start event without group-id. Consider implem
    49 enting group-id handling in the upstream elements
    50 2017-02-10 05:19:13,222 DEBUG   [mediagoblin.media_types.audio.transcoders] <flags GST_MESSAGE_STREAM_START of type Gst.MessageType>
    51 ...
    52 
    53 ...             
    54 2017-02-10 05:19:41,405 DEBUG   [mediagoblin.media_types.audio.transcoders] <flags GST_MESSAGE_ELEMENT of type Gst.MessageType>
    55 2017-02-10 05:19:41,405 INFO    [mediagoblin.media_types.audio.transcoders] 100% done...
    56 2017-02-10 05:19:41,406 DEBUG   [mediagoblin.media_types.audio.transcoders] <flags GST_MESSAGE_EOS of type Gst.MessageType>
    57 2017-02-10 05:19:41,406 INFO    [mediagoblin.media_types.audio.transcoders] Done                                                                   
    58 0:07:18.514617756  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking mpegaudioparse1:src(0xacee0bc8) and mad1:sink(0xb5f9d1d8)
    59 0:07:18.514735089  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked mpegaudioparse1:src and mad1:sink
    60 0:07:18.514895444  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking mad1:src(0xb5f9d318) and src_0:proxypad3(0xace70978)
    61 0:07:18.515024021  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked mad1:src and src_0:proxypad3
    62 0:07:18.515141354  8461 0x81ee03c0 INFO           GST_PARENTAGE gstbin.c:1816:gst_bin_remove_func:<decodebin> removed child "mad1"
    63 0:07:18.515339842  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking typefind:src(0xace7c9b8) and mpegaudioparse1:sink(0xace7cd78)
    64 0:07:18.515471352  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked typefind:src and mpegaudioparse1:sink
    65 0:07:18.515606285  8461 0x81ee03c0 INFO           GST_PARENTAGE gstbin.c:1816:gst_bin_remove_func:<decodebin> removed child "mpegaudioparse1"
    66 0:07:18.515712862  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<decodebin> removing pad 'src_0'
    67 0:07:18.515837039  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstpad.c:2071:gst_pad_unlink: unlinking decodebin:src_0(0x810a9480) and queue:sink(0x810842e8)
    68 0:07:18.515963661  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstpad.c:2125:gst_pad_unlink: unlinked decodebin:src_0 and queue:sink
    69 ...
    70 0:07:18.586227429  8461 0x81ee03c0 INFO              GST_STATES gstbin.c:2963:gst_bin_change_state_func:<pipeline1> child 'filesrc' changed state to 1(NULL) successfully
    71 0:07:18.586445961  8461 0x81ee03c0 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<mpegaudioparse1> 0xb5f781f8 dispose
    72 0:07:18.586483116  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<mpegaudioparse1> removing pad 'sink'
    73 0:07:18.586534450  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<mpegaudioparse1> removing pad 'src'
    74 0:07:18.586581383  8461 0x81ee03c0 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<mpegaudioparse1> 0xb5f781f8 parent class dispose
    75 0:07:18.588930972  8461 0x81ee03c0 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<mpegaudioparse1> 0xb5f781f8 finalize
    76 0:07:18.589075682  8461 0x81ee03c0 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<mpegaudioparse1> 0xb5f781f8 finalize parent
    77 0:07:18.589188126  8461 0x81ee03c0 INFO         GST_REFCOUNTING gstelement.c:2994:gst_element_dispose:<mad1> 0x810a0f08 dispose
    78 0:07:18.589298615  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<mad1> removing pad 'sink'
    79 0:07:18.589413992  8461 0x81ee03c0 INFO        GST_ELEMENT_PADS gstelement.c:785:gst_element_remove_pad:<mad1> removing pad 'src'
    80 0:07:18.589517636  8461 0x81ee03c0 INFO         GST_REFCOUNTING gstelement.c:3040:gst_element_dispose:<mad1> 0x810a0f08 parent class dispose
    81 0:07:18.589623235  8461 0x81ee03c0 INFO         GST_REFCOUNTING gstelement.c:3071:gst_element_finalize:<mad1> 0x810a0f08 finalize
    82 0:07:18.589815368  8461 0x81ee03c0 INFO         GST_REFCOUNTING gstelement.c:3077:gst_element_finalize:<mad1> 0x810a0f08 finalize parent
    83 0:07:18.590644031  8461 0x81ee03c0 INFO              GST_STATES gstelement.c:2419:gst_element_continue_state:<pipeline1> completed state change to NULL
    84 2017-02-10 05:22:14,059 INFO    [mediagoblin.media_types.audio.transcoders] Quitting MainLoop gracefully...
    85 [skipped gst output]
    86 2017-02-10 05:22:17,321 ERROR   [mediagoblin.processing.task] An unhandled exception was raised while processing <MediaEntry 34: 20150706-focuseuropan-w2575>
    87 2017-02-10 05:22:17,323 WARNING [mediagoblin.processing] No idea what happened here, but it failed: IndexError('axis 1 out of bounds [0, 1)',)
    88 2017-02-10 05:22:17,370 DEBUG   [mediagoblin.tools.processing] No processing callback URL for <MediaEntry 34: 20150706-focuseuropan-w2575>
    89 2017-02-10 05:22:17,373 WARNING [mediagoblin.processing] No idea what happened here, but it failed: IndexError('axis 1 out of bounds [0, 1)',)
    90 }}}
    91 
    92 {{{
    93 194:def halt(self):
    94         if getattr(self, 'pipeline', False):
    95             self.pipeline.set_state(Gst.State.NULL)
    96             del self.pipeline
    97 198:        _log.info('Quitting MainLoop gracefully...')
    98         GObject.idle_add(self._loop.quit)
    99 }}}
    100 
    101 mediagoblin/processing/task.py
    102 {{{
    103 class ProcessMedia(celery.Task):
    104 ...
    105        # Try to process, and handle expected errors.
    106         try:
    107             processor_class = manager.get_processor(reprocess_action, entry)
    108 
    109             with processor_class(manager, entry) as processor:
    110                 # Initial state change has to be here because
    111                 # the entry.state gets recorded on processor_class init
    112                 entry.state = u'processing'
    113                 entry.save()
    114 
    115                 _log.debug('Processing {0}'.format(entry))
    116 
    117                 try:
    118                     processor.process(**reprocess_info)
    119                 except Exception as exc:
    120                     if processor.entry_orig_state == 'processed':
    121                         _log.error(
    122                             'Entry {0} failed to process due to the following'
    123                             ' error: {1}'.format(entry.id, exc))
    124                         _log.info(
    125                             'Setting entry.state back to "processed"')
    126                         pass
    127                     else:
    128                         raise
    129 
    130             # We set the state to processed and save the entry here so there's
    131             # no need to save at the end of the processing stage, probably ;)
    132             entry.state = u'processed'
    133             entry.save()
    134 
    135             # Notify the PuSH servers as async task
    136             if mgg.app_config["push_urls"] and feed_url:
    137                 handle_push_urls.subtask().delay(feed_url)
    138 
    139             json_processing_callback(entry)
    140         except BaseProcessingFail as exc:
    141             mark_entry_failed(entry.id, exc)
    142             json_processing_callback(entry)
    143             return
    144 
    145         except ImportError as exc:
    146             _log.error(
    147                 'Entry {0} failed to process due to an import error: {1}'\
    148                     .format(
    149                     entry.title,
    150                     exc))
    151 
    152             mark_entry_failed(entry.id, exc)
    153             json_processing_callback(entry)
    154 
    155         except Exception as exc:
    156 133:            _log.error('An unhandled exception was raised while'
    157                     + ' processing {0}'.format(
    158                         entry))
    159 
    160             mark_entry_failed(entry.id, exc)
    161             json_processing_callback(entry)
    162             raise
    163 }}}
    164 
    165 mediagoblin/tools/processing
    166 {{{
    167 ef json_processing_callback(entry):
    168     '''
    169     Send an HTTP post to the registered callback url, if any.
    170     '''
    171     if not entry.processing_metadata:
    172         _log.debug('No processing callback URL for {0}'.format(entry))
    173         return
    174 }}}
    175 
    176 mediagoblin/processing/__init__.py
    177 {{{
    178 def mark_entry_failed(entry_id, exc):
    179     """
    180     Mark a media entry as having failed in its conversion.
    181 
    182     Uses the exception that was raised to mark more information.  If
    183     the exception is a derivative of BaseProcessingFail then we can
    184     store extra information that can be useful for users telling them
    185     why their media failed to process.
    186 
    187     :param entry_id: The id of the media entry
    188     :param exc: An instance of BaseProcessingFail
    189 
    190     """
    191     # Was this a BaseProcessingFail?  In other words, was this a
    192     # type of error that we know how to handle?
    193     if isinstance(exc, BaseProcessingFail):
    194         # Looks like yes, so record information about that failure and any
    195         # metadata the user might have supplied.
    196         atomic_update(mgg.database.MediaEntry,
    197             {'id': entry_id},
    198             {u'state': u'failed',
    199              u'fail_error': six.text_type(exc.exception_path),
    200              u'fail_metadata': exc.metadata})
    201     else:
    202         _log.warn("No idea what happened here, but it failed: %r", exc)
    203         # Looks like no, let's record it so that admin could ask us about the
    204         # reason
    205         atomic_update(mgg.database.MediaEntry,
    206             {'id': entry_id},
    207             {u'state': u'failed',
    208              u'fail_error': u'Unhandled exception: {0}'.format(
    209                  six.text_type(exc)),
    210              u'fail_metadata': {}})
    211 }}}
    212 
    213 According to ticket:5457#comment:12 Numpy 1.11.2 and AudioLab 0.11.0 are incompatible (here numpy==1.12.0, scikits.audiolab==0.11.0). The proposed fix
     3The workaround of ticket:5457#comment:12
    2144
    2155{{{
    … …  
    2177./bin/pip install scikits.audiolab==0.10.2
    2188}}}
    219 solves this issue for me as well.
    220 
    221 Possible explanation from chat: the actual issue is that numpy deprecated some code, but the third-party freesound audio processing file that we imported as an external library hasn't been updated to work with the more recent code.
     9solves this issue for me as well. Thanks ayleph for looking it up