diff --git a/CHANGELOG.md b/CHANGELOG.md index 3e9babee4..eade334dc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,9 @@ can and probably will change functionality and break backwards compatability at anytime. ## [Unreleased] +### Fixed + * Add better logging to help track down [#478](https://github.com/lbryio/lbry/issues/478) + ## [0.8.3rc3] - 2017-02-14 @@ -16,6 +19,7 @@ at anytime. ## [0.8.3rc1] - 2017-02-13 ### Changed * make connection manager unit testeable + ### Fixed * Change EWOULDBLOCK error in DHT to warning. #481 * mark peers as down if it fails download protocol @@ -32,7 +36,7 @@ at anytime. * Convert GetStream to inclineCallbacks * Change callback condition in GetStream to the first data blob completing * Add local and remote heights to blockchain status - + ### Fixed * Fix recursion depth error upon failed blob * Call stopProducing in reflector client file_sender when uploading is done @@ -44,12 +48,12 @@ at anytime. * Fix updating a claim where the stream doesn't change * Fix claim_abandon - ## [0.8.1] - 2017-02-01 ### Changed * reflect all the blobs in a stream * change command line flags so that the more common usage is the default * change daemon function signatures to include names arguments + ### Fixed * disable verbose twisted logs * improved wallet balance calculations @@ -61,6 +65,7 @@ at anytime. * improved command line user experience * integrate twisted logging with python logging * Updated READMEs + ### Fixed * Fixed bug where ConnectionManager wasn't being stopped * Fixed: #343 diff --git a/lbrynet/lbryfilemanager/EncryptedFileDownloader.py b/lbrynet/lbryfilemanager/EncryptedFileDownloader.py index 5b69d982d..e1035df31 100644 --- a/lbrynet/lbryfilemanager/EncryptedFileDownloader.py +++ b/lbrynet/lbryfilemanager/EncryptedFileDownloader.py @@ -51,7 +51,7 @@ class ManagedEncryptedFileDownloader(EncryptedFileSaver): if sd_hash: self.sd_hash = sd_hash[0] else: - raise Exception("No sd hash for stream hash %s", self.stream_hash) + raise Exception("No sd hash for stream hash %s" % self.stream_hash) claim_metadata = yield self.wallet.get_claim_metadata_for_sd_hash(self.sd_hash) if claim_metadata is None: raise Exception("A claim doesn't exist for sd %s" % self.sd_hash) @@ -59,7 +59,10 @@ class ManagedEncryptedFileDownloader(EncryptedFileSaver): self.claim_id = yield self.wallet.get_claimid(self.uri, self.txid, self.nout) status = yield self.lbry_file_manager.get_lbry_file_status(self) if status == ManagedEncryptedFileDownloader.STATUS_RUNNING: - yield self.start() + # start returns self.finished_deferred + # which fires when we've finished downloading the file + # and we don't want to wait for the entire download + self.start() elif status == ManagedEncryptedFileDownloader.STATUS_STOPPED: defer.returnValue(False) elif status == ManagedEncryptedFileDownloader.STATUS_FINISHED: @@ -96,6 +99,7 @@ class ManagedEncryptedFileDownloader(EncryptedFileSaver): @defer.inlineCallbacks def _start(self): + log.info('Starting Downloader for %s', self.stream_hash) yield EncryptedFileSaver._start(self) sd_hash = yield self.stream_info_manager.get_sd_blob_hashes_for_stream(self.stream_hash) if len(sd_hash): @@ -107,6 +111,7 @@ class ManagedEncryptedFileDownloader(EncryptedFileSaver): self.txid = txid self.nout = nout status = yield self._save_status() + log.info('Set Downloader status for %s to %s', self.stream_hash, status) defer.returnValue(status) def _get_finished_deferred_callback_value(self): diff --git a/lbrynet/lbryfilemanager/EncryptedFileManager.py b/lbrynet/lbryfilemanager/EncryptedFileManager.py index 1fca82272..b4ad6b7c4 100644 --- a/lbrynet/lbryfilemanager/EncryptedFileManager.py +++ b/lbrynet/lbryfilemanager/EncryptedFileManager.py @@ -43,7 +43,6 @@ class EncryptedFileManager(object): self.stream_info_manager = stream_info_manager self.sd_identifier = sd_identifier self.lbry_files = [] - self.lbry_files_setup_deferred = None self.sql_db = None if download_directory: self.download_directory = download_directory @@ -114,29 +113,27 @@ class EncryptedFileManager(object): yield defer.DeferredList(list(_iter_streams(stream_hashes))) @defer.inlineCallbacks - def _restore_lbry_file(self, lbry_file): - try: - yield lbry_file.restore() - except Exception as err: - log.error("Failed to start stream: %s, error: %s", lbry_file.stream_hash, err) - self.lbry_files.remove(lbry_file) - # TODO: delete stream without claim instead of just removing from manager? + def _start_lbry_files(self): + yield self._check_stream_info_manager() + files_and_options = yield self._get_all_lbry_files() + yield defer.DeferredList([ + self._set_options_and_restore(rowid, stream_hash, options) + for rowid, stream_hash, options in files_and_options + ]) + log.info("Started %i lbry files", len(self.lbry_files)) @defer.inlineCallbacks - def _start_lbry_files(self): - b_prm = self.session.base_payment_rate_manager - payment_rate_manager = NegotiatedPaymentRateManager(b_prm, self.session.blob_tracker) - yield self._check_stream_info_manager() - lbry_files_and_options = yield self._get_all_lbry_files() - dl = [] - for rowid, stream_hash, options in lbry_files_and_options: - lbry_file = yield self.start_lbry_file(rowid, stream_hash, payment_rate_manager, - blob_data_rate=options) - dl.append(self._restore_lbry_file(lbry_file)) - log.debug("Started %s", lbry_file) - self.lbry_files_setup_deferred = defer.DeferredList(dl) - log.info("Started %i lbry files", len(self.lbry_files)) - defer.returnValue(True) + def _set_options_and_restore(self, rowid, stream_hash, options): + try: + b_prm = self.session.base_payment_rate_manager + payment_rate_manager = NegotiatedPaymentRateManager( + b_prm, self.session.blob_tracker) + downloader = yield self.start_lbry_file( + rowid, stream_hash, payment_rate_manager, blob_data_rate=options) + yield downloader.restore() + except Exception: + log.exception('An error occurred while starting a lbry file (%s, %s, %s)', + rowid, stream_hash, options) @defer.inlineCallbacks def start_lbry_file(self, rowid, stream_hash, @@ -145,16 +142,23 @@ class EncryptedFileManager(object): if not download_directory: download_directory = self.download_directory payment_rate_manager.min_blob_data_payment_rate = blob_data_rate - lbry_file = ManagedEncryptedFileDownloader(rowid, stream_hash, self.session.peer_finder, - self.session.rate_limiter, - self.session.blob_manager, - self.stream_info_manager, - self, payment_rate_manager, self.session.wallet, - download_directory, upload_allowed, - file_name=file_name) - yield lbry_file.set_stream_info() - self.lbry_files.append(lbry_file) - defer.returnValue(lbry_file) + lbry_file_downloader = ManagedEncryptedFileDownloader( + rowid, + stream_hash, + self.session.peer_finder, + self.session.rate_limiter, + self.session.blob_manager, + self.stream_info_manager, + self, + payment_rate_manager, + self.session.wallet, + download_directory, + upload_allowed, + file_name=file_name + ) + yield lbry_file_downloader.set_stream_info() + self.lbry_files.append(lbry_file_downloader) + defer.returnValue(lbry_file_downloader) @defer.inlineCallbacks def _stop_lbry_file(self, lbry_file): diff --git a/lbrynet/lbrynet_daemon/Daemon.py b/lbrynet/lbrynet_daemon/Daemon.py index 8b54148ba..fc1a34e58 100644 --- a/lbrynet/lbrynet_daemon/Daemon.py +++ b/lbrynet/lbrynet_daemon/Daemon.py @@ -649,18 +649,19 @@ class Daemon(AuthJSONRPCServer): session_id=self._session_id ) + @defer.inlineCallbacks def _setup_lbry_file_manager(self): + log.info('Starting to setup up file manager') self.startup_status = STARTUP_STAGES[3] - d = self.stream_info_manager.setup() - - def set_lbry_file_manager(): - self.lbry_file_manager = EncryptedFileManager( - self.session, self.stream_info_manager, - self.sd_identifier, download_directory=self.download_directory) - return self.lbry_file_manager.setup() - - d.addCallback(lambda _: set_lbry_file_manager()) - return d + yield self.stream_info_manager.setup() + self.lbry_file_manager = EncryptedFileManager( + self.session, + self.stream_info_manager, + self.sd_identifier, + download_directory=self.download_directory + ) + yield self.lbry_file_manager.setup() + log.info('Done setting up file manager') def _get_analytics(self): if not self.analytics_manager.is_started: