Hello Ruairi,
Your logger changes look fine to me. I applied a few of them on top of the current qa/1.x branch in my development environment and they seem to work:
replaceafill@vm1:~/archivematica$ git diff src/
diff --git a/src/archivematica/MCPClient/clientScripts/create_transfer_mets.py b/src/archivematica/MCPClient/clientScripts/create_transfer_mets.py
index 02adbb416..0fa032dd7 100755
--- a/src/archivematica/MCPClient/clientScripts/create_transfer_mets.py
+++ b/src/archivematica/MCPClient/clientScripts/create_transfer_mets.py
@@ -47,7 +47,9 @@ IE_PREMIS_META["xsi:type"] = "premis:intellectualEntity"
logger = logging.getLogger(__name__)
+logger.setLevel(logging.INFO)
+logger.info("**TEST** Logging is working inside create_transfer_mets.")
def write_mets(mets_path, transfer_dir_path, base_path_placeholder, transfer_uuid):
"""
@@ -809,7 +811,10 @@ def call(jobs):
for job in jobs:
with job.JobContext(logger=logger):
+ print("**TEST** finished create_transfer_mets")
+ logger.info("**TEST** about to start create_transfer_mets")
args = parser.parse_args(job.args[1:])
write_mets(
args.xml_file, args.base_path, args.base_path_string, args.sip_uuid
)
+ logger.info("**TEST** finished create_transfer_mets")
Then I restarted the AM services and flushed/cleared my container logs (this is an irreversible operation btw) to start fresh:
replaceafill@vm1:~/archivematica/hack$ make restart-am-services
replaceafill@vm1:~/archivematica/hack$ sudo make flush-logs
Then I ran a transfer and your logs are there:
replaceafill@vm1:~/archivematica/hack$ docker compose logs archivematica-mcp-client | grep '**TEST**'
archivematica-mcp-client-1 | **TEST** finished create_transfer_mets
archivematica-mcp-client-1 | archivematicaClient.py: INFO 2025-06-06 16:20:19,037 archivematica.MCPClient.clientScripts.create_transfer_mets:call:815: **TEST** about to start create_transfer_mets
archivematica-mcp-client-1 | archivematicaClient.py: INFO 2025-06-06 16:20:19,193 archivematica.MCPClient.clientScripts.create_transfer_mets:call:820: **TEST** finished create_transfer_mets
If you wonder why the "Logging is working inside create_transfer_mets" line is not here it's because it is only written when the MCPClient service starts and parses the module. Since I flushed the logs it was lost. If I restart the services it's printed again:
replaceafill@vm1:~/archivematica/hack$ make restart-am-services
docker compose restart --no-deps archivematica-mcp-server
[+] Restarting 1/1
✔ Container am-archivematica-mcp-server-1 Started 2.2s
docker compose restart --no-deps archivematica-mcp-client
[+] Restarting 1/1
✔ Container am-archivematica-mcp-client-1 Started 1.3s
docker compose restart --no-deps archivematica-dashboard
[+] Restarting 1/1
✔ Container am-archivematica-dashboard-1 Started 1.5s
docker compose restart --no-deps archivematica-storage-service
[+] Restarting 1/1
✔ Container am-archivematica-storage-service-1 Started 1.7s
replaceafill@vm1:~/archivematica/hack$ docker compose logs archivematica-mcp-client | grep '**TEST**'
archivematica-mcp-client-1 | **TEST** finished create_transfer_mets
archivematica-mcp-client-1 | archivematicaClient.py: INFO 2025-06-06 16:20:19,037 archivematica.MCPClient.clientScripts.create_transfer_mets:call:815: **TEST** about to start create_transfer_mets
archivematica-mcp-client-1 | archivematicaClient.py: INFO 2025-06-06 16:20:19,193 archivematica.MCPClient.clientScripts.create_transfer_mets:call:820: **TEST** finished create_transfer_mets
archivematica-mcp-client-1 | archivematicaClient.py: INFO 2025-06-06 16:30:53,225 archivematica.MCPClient.clientScripts.create_transfer_mets:<module>:52: **TEST** Logging is working inside create_transfer_mets.
What do you see in your MCPClient logs after *** RUNNING TASK: createtransfermets_v1.0*** when your transfer runs?