2021-06-03 15:20:39 +02:00
|
|
|
import hashlib
|
2023-02-26 01:27:00 +01:00
|
|
|
import logging
|
2021-06-03 15:20:39 +02:00
|
|
|
import os
|
2015-06-22 21:49:23 +02:00
|
|
|
import time
|
2022-08-21 11:28:57 +02:00
|
|
|
from queue import Empty, Queue
|
2021-06-03 15:20:39 +02:00
|
|
|
from threading import Thread
|
2023-02-26 00:11:49 +01:00
|
|
|
from typing import Optional
|
2021-06-03 15:20:39 +02:00
|
|
|
|
2023-03-01 17:13:02 +01:00
|
|
|
import requests
|
2022-07-22 13:27:16 +02:00
|
|
|
from libretime_api_client.v2 import ApiClient
|
2014-07-10 23:56:41 +02:00
|
|
|
|
2023-02-26 00:11:49 +01:00
|
|
|
from .events import FileEvent, FileEvents
|
|
|
|
|
2023-02-26 01:27:00 +01:00
|
|
|
logger = logging.getLogger(__name__)
|
|
|
|
|
2012-03-01 23:58:44 +01:00
|
|
|
|
|
|
|
class PypoFile(Thread):
|
2022-08-14 19:55:39 +02:00
|
|
|
name = "file"
|
2022-09-08 17:55:51 +02:00
|
|
|
daemon = True
|
2022-08-14 19:55:39 +02:00
|
|
|
|
2023-03-21 19:40:56 +01:00
|
|
|
file_events_queue: "Queue[FileEvents]"
|
2023-02-26 00:11:49 +01:00
|
|
|
file_events: FileEvents
|
|
|
|
|
2022-08-21 11:28:57 +02:00
|
|
|
def __init__(
|
|
|
|
self,
|
2023-03-21 19:40:56 +01:00
|
|
|
file_queue: "Queue[FileEvents]",
|
2022-08-21 11:28:57 +02:00
|
|
|
api_client: ApiClient,
|
|
|
|
):
|
2012-03-01 23:58:44 +01:00
|
|
|
Thread.__init__(self)
|
2023-02-26 00:11:49 +01:00
|
|
|
self.file_events_queue = file_queue
|
|
|
|
self.file_events = {}
|
2022-07-22 16:26:43 +02:00
|
|
|
self.api_client = api_client
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2023-02-26 00:11:49 +01:00
|
|
|
def copy_file(self, file_event: FileEvent):
|
2012-03-01 23:58:44 +01:00
|
|
|
"""
|
2023-02-26 00:11:49 +01:00
|
|
|
Copy file_event from local library directory to local cache directory.
|
2012-06-26 23:00:14 +02:00
|
|
|
"""
|
2023-03-04 21:50:12 +01:00
|
|
|
if file_event.local_filepath.is_file():
|
|
|
|
logger.debug(
|
|
|
|
"found file %s in cache %s",
|
|
|
|
file_event.id,
|
|
|
|
file_event.local_filepath,
|
|
|
|
)
|
|
|
|
file_event.file_ready = True
|
|
|
|
return
|
|
|
|
|
|
|
|
logger.info(
|
|
|
|
"copying file %s to cache %s",
|
|
|
|
file_event.id,
|
|
|
|
file_event.local_filepath,
|
|
|
|
)
|
2012-04-13 21:23:01 +02:00
|
|
|
try:
|
2024-01-01 13:16:13 +01:00
|
|
|
try:
|
|
|
|
with file_event.local_filepath.open("wb") as file_fd:
|
2023-03-04 21:50:12 +01:00
|
|
|
response = self.api_client.download_file(file_event.id, stream=True)
|
2024-01-01 13:07:27 +01:00
|
|
|
for chunk in response.iter_content(chunk_size=8192):
|
2023-03-04 21:50:12 +01:00
|
|
|
file_fd.write(chunk)
|
|
|
|
|
2024-01-01 13:16:13 +01:00
|
|
|
except requests.exceptions.HTTPError as exception:
|
|
|
|
file_event.local_filepath.unlink(missing_ok=True)
|
|
|
|
|
|
|
|
raise RuntimeError(
|
|
|
|
f"could not download file {file_event.id}"
|
|
|
|
) from exception
|
2023-03-04 21:50:12 +01:00
|
|
|
|
|
|
|
# make file world readable and owner writable
|
|
|
|
file_event.local_filepath.chmod(0o644)
|
|
|
|
|
|
|
|
if file_event.filesize == 0:
|
|
|
|
file_event.filesize = self.report_file_size_and_md5_to_api(
|
|
|
|
str(file_event.local_filepath),
|
|
|
|
file_event.id,
|
2023-02-26 12:01:59 +01:00
|
|
|
)
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2023-03-04 21:50:12 +01:00
|
|
|
file_event.file_ready = True
|
|
|
|
except Exception as exception: # pylint: disable=broad-exception-caught
|
|
|
|
logger.exception(
|
|
|
|
"could not copy file %s to %s: %s",
|
|
|
|
file_event.id,
|
|
|
|
file_event.local_filepath,
|
|
|
|
exception,
|
|
|
|
)
|
|
|
|
|
2023-02-26 00:11:49 +01:00
|
|
|
def report_file_size_and_md5_to_api(self, file_path: str, file_id: int) -> int:
|
2015-02-24 17:00:41 +01:00
|
|
|
try:
|
|
|
|
file_size = os.path.getsize(file_path)
|
|
|
|
|
2023-03-01 17:13:02 +01:00
|
|
|
with open(file_path, "rb") as file_fd:
|
fix(playout): improve the way hashlib is called in libretime_playout/player (#3135)
### Description
Improves the way hashlib is called in libretime_playout/player so that
is isn't broken on systems with python < 3.9
The way it is currently called in
site-packages/libretime_playout/player/file.py, in the section where
scheduled files are copied to the cache dir for playout, specifies the
usedforsecurity=False flag as follows:
`hasher = hashlib.md5(usedforsecurity=False)`
hashlib.md5 did not support this flag until Python 3.9. Attempting to
specify the flag directly as an argument to hashlib.md5(), in an older
python environment (such as that in Ubuntu Focal 20.04), is unsafe, and
can cause hashlib.md5() to balk/throw an exception, which results in
file copy operations failing. This then precipitates into playout
problems, as scheduled media is missing from the cache folder.
This PR instead calls using hashlib.new(), and passes the argument to
that, as follows:
`hasher = hashlib.new('md5', usedforsecurity=False)`
This method of calling with the flag argument is safer, because the
constructor will take it or leave it gracefully, regardless of whether
the system has a version of hashlib that supports the `usedforsecurity`
flag. AFAICT, it improves (fixes) function on older systems without
negatively impacting others.
### Testing Notes
**What I did:**
Before applying this patch, we were experiencing occasional but fairly
regular periods of silence when the system was supposed to be playing a
song or track. This behavior was consistent with errors such as the
following being present in the playout log:
```
2025-01-15 14:01:28,331 | INFO | libretime_playout.player.file:copy_file:47 - copying file 19834 to cache /var/lib/libretime/playout/scheduler/19834.mp3
2025-01-15 14:01:28,466 | ERROR | libretime_playout.player.file:copy_file:77 - could not copy file 19834 to /var/lib/libretime/playout/scheduler/19834.mp3: 'usedforsecurity' is an invalid keyword argument for openssl_md5()
Traceback (most recent call last):
File "/opt/libretime/lib/python3.8/site-packages/libretime_playout/player/file.py", line 70, in copy_file
file_event.filesize = self.report_file_size_and_md5_to_api(
File "/opt/libretime/lib/python3.8/site-packages/libretime_playout/player/file.py", line 89, in report_file_size_and_md5_to_api
hasher = hashlib.md5(usedforsecurity=False)
TypeError: 'usedforsecurity' is an invalid keyword argument for openssl_md5()
```
_For more information about the characterization and results of this
problem, see issue #3134_
**Testing on running systems**
After the patch was applied, these errors were no longer seen. I first
tested this on a dev server, and then on a live server, with
approximately 100 distinct tracks of playout occurring over about 24
hours. There were no file copy failures, and no related playout
problems, which was a major and immediate improvement.
**Testing installer, fresh installs**
***Ubuntu 20.04***
I deployed a patch to the installer and installed it on a blank system
running Ubuntu 20.04 and tested it to make sure the fix was applied and
worked.
***Debian 11***
I deployed patch to the installer and installed it on a blank system
running Debian Bullseye (which runs python = 3.9) , and tested it there
to make sure it did not break anything or introduce a regression.
### **Links**
Closes: #3134
2025-01-18 00:11:02 +01:00
|
|
|
hasher = hashlib.new("md5", usedforsecurity=False)
|
2015-02-24 17:00:41 +01:00
|
|
|
while True:
|
2023-03-01 17:13:02 +01:00
|
|
|
data = file_fd.read(8192)
|
2015-02-24 17:00:41 +01:00
|
|
|
if not data:
|
|
|
|
break
|
2023-02-26 00:11:49 +01:00
|
|
|
hasher.update(data)
|
|
|
|
md5_hash = hasher.hexdigest()
|
2022-08-09 21:05:21 +02:00
|
|
|
except OSError as exception:
|
2015-02-24 17:00:41 +01:00
|
|
|
file_size = 0
|
2022-08-09 21:05:21 +02:00
|
|
|
logger.exception(
|
2023-02-26 12:01:59 +01:00
|
|
|
"Error getting file size and md5 hash for file id %s: %s",
|
|
|
|
file_id,
|
|
|
|
exception,
|
2021-05-27 16:23:02 +02:00
|
|
|
)
|
2015-02-24 17:00:41 +01:00
|
|
|
|
2021-08-20 13:35:33 +02:00
|
|
|
# Make PUT request to LibreTime to update the file size and hash
|
2022-08-09 21:05:21 +02:00
|
|
|
error_msg = f"Could not update media file {file_id} with file size and md5 hash"
|
2017-10-03 03:37:06 +02:00
|
|
|
try:
|
2022-07-22 15:41:38 +02:00
|
|
|
self.api_client.update_file(
|
|
|
|
file_id,
|
|
|
|
json={"filesize": file_size, "md5": md5_hash},
|
|
|
|
)
|
2023-03-01 17:13:02 +01:00
|
|
|
except (requests.exceptions.ConnectionError, requests.exceptions.Timeout):
|
2022-08-09 21:05:21 +02:00
|
|
|
logger.exception(error_msg)
|
2023-03-01 18:17:34 +01:00
|
|
|
except Exception as exception: # pylint: disable=broad-exception-caught
|
2023-02-26 12:01:59 +01:00
|
|
|
logger.exception("%s: %s", error_msg, exception)
|
2015-02-24 17:00:41 +01:00
|
|
|
|
|
|
|
return file_size
|
|
|
|
|
2023-02-26 00:11:49 +01:00
|
|
|
def get_highest_priority_file_event(
|
|
|
|
self,
|
|
|
|
file_events: FileEvents,
|
|
|
|
) -> Optional[FileEvent]:
|
2012-03-01 23:58:44 +01:00
|
|
|
"""
|
2023-02-26 00:11:49 +01:00
|
|
|
Get highest priority file event in the queue. Currently the highest
|
2012-03-01 23:58:44 +01:00
|
|
|
priority is decided by how close the start time is to "now".
|
|
|
|
"""
|
2023-02-26 00:11:49 +01:00
|
|
|
if file_events is None or len(file_events) == 0:
|
2012-03-01 23:58:44 +01:00
|
|
|
return None
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2023-02-26 00:11:49 +01:00
|
|
|
sorted_keys = sorted(file_events.keys())
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2012-03-01 23:58:44 +01:00
|
|
|
if len(sorted_keys) == 0:
|
|
|
|
return None
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2012-03-01 23:58:44 +01:00
|
|
|
highest_priority = sorted_keys[0]
|
2023-02-26 00:11:49 +01:00
|
|
|
file_event = file_events[highest_priority]
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2023-02-26 12:01:59 +01:00
|
|
|
logger.debug("Highest priority item: %s", highest_priority)
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2022-07-01 12:23:18 +02:00
|
|
|
# Remove this media_item from the dictionary. On the next iteration
|
|
|
|
# (from the main function) we won't consider it for prioritization
|
|
|
|
# anymore. If on the next iteration we have received a new schedule,
|
|
|
|
# it is very possible we will have to deal with the same media_items
|
|
|
|
# again. In this situation, the worst possible case is that we try to
|
|
|
|
# copy the file again and realize we already have it (thus aborting the copy).
|
2023-02-26 00:11:49 +01:00
|
|
|
del file_events[highest_priority]
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2023-02-26 00:11:49 +01:00
|
|
|
return file_event
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2012-03-01 23:58:44 +01:00
|
|
|
def main(self):
|
|
|
|
while True:
|
|
|
|
try:
|
2023-02-26 00:11:49 +01:00
|
|
|
if self.file_events is None or len(self.file_events) == 0:
|
2022-07-01 12:23:18 +02:00
|
|
|
# We have no schedule, so we have nothing else to do. Let's
|
|
|
|
# do a blocked wait on the queue
|
2023-02-26 00:11:49 +01:00
|
|
|
self.file_events = self.file_events_queue.get(block=True)
|
2012-03-01 23:58:44 +01:00
|
|
|
else:
|
2022-07-01 12:23:18 +02:00
|
|
|
# We have a schedule we need to process, but we also want
|
|
|
|
# to check if a newer schedule is available. In this case
|
|
|
|
# do a non-blocking queue.get and in either case (we get something
|
|
|
|
# or we don't), get back to work on preparing getting files.
|
2012-03-01 23:58:44 +01:00
|
|
|
try:
|
2023-02-26 00:11:49 +01:00
|
|
|
self.file_events = self.file_events_queue.get_nowait()
|
2022-08-09 21:05:21 +02:00
|
|
|
except Empty:
|
2012-03-01 23:58:44 +01:00
|
|
|
pass
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2023-02-26 00:11:49 +01:00
|
|
|
file_event = self.get_highest_priority_file_event(self.file_events)
|
|
|
|
if file_event is not None:
|
|
|
|
self.copy_file(file_event)
|
2023-03-01 18:17:34 +01:00
|
|
|
except Exception as exception: # pylint: disable=broad-exception-caught
|
2022-08-09 21:05:21 +02:00
|
|
|
logger.exception(exception)
|
|
|
|
raise exception
|
2012-06-26 23:00:14 +02:00
|
|
|
|
2012-03-01 23:58:44 +01:00
|
|
|
def run(self):
|
|
|
|
"""
|
|
|
|
Entry point of the thread
|
|
|
|
"""
|
2021-05-27 16:23:02 +02:00
|
|
|
try:
|
|
|
|
self.main()
|
2023-03-01 18:17:34 +01:00
|
|
|
except Exception as exception: # pylint: disable=broad-exception-caught
|
2022-08-09 21:05:21 +02:00
|
|
|
logger.exception(exception)
|
2015-06-22 21:49:23 +02:00
|
|
|
time.sleep(5)
|
2022-08-09 21:05:21 +02:00
|
|
|
|
2022-01-13 16:11:37 +01:00
|
|
|
logger.info("PypoFile thread exiting")
|