Pulp

++ This bug was initially created as a clone of Bugzilla Bug #1129817 ++

Description of problem:

Description of problem: The Pulp logger divides log messages with newline characters in them into multiple log messages. This can create an interleaving issue where multiple processes all report the same traceback at the same time and it is difficult to read.

Loggers can use the PID setting which helps resolve this issue, but that is not on by default, and it also cannot solve cases where multiple threads interleave tracebacks.

This RFE requests that when the Pulp logger splits a log message into multiple independent lines, a short but unique identifier be added to the front of each multi-line message so that the user can easily determine which lines go together

Potentially the object ID of the original, long message could be used.

--- Additional comment from rbarlow@redhat.com at 09/12/2014 15:13:07 ---

The fix will be in server/pulp/server/logs.py in the CompliantSysLogHandler class. Use process_id-thread_id as the identifier. Be aware that there are two ways that messages can get split:

1) For having newlines. Each newline split needs this identifier.
2) For having lines that are too long (>2041 bytes). Each split message also needs this identifier.

1 and 2 can happen in the same message, so watch out for that.

The tests for that module are in server/test/unit/server/test_logs.py.

--- Additional comment from amacdona@redhat.com at 09/16/2014 11:50:20 ---

Addressed with pull request https://github.com/pulp/pulp/pull/1159

--- Additional comment from cduryee@redhat.com at 12/23/2014 20:52:35 ---

fixed in pulp 2.6.0-0.2.beta

--- Additional comment from pthomas@redhat.com at 01/29/2015 15:46:08 ---

verified
[root@cloud-qe-4 ~]# rpm -qa pulp-server
pulp-server-2.6.0-0.5.beta.el7.noarch

checked in the log messages for both rhel6 & rhel7

For example
el7

Jan 29 10:07:52 cloud-qe-4.idmqe.lab.eng.bos.redhat.com pulp[28902]: celery.worker.job:ERROR: (28902-87040) raise MissingResource(repository=repo_id)
Jan 29 10:07:52 cloud-qe-4.idmqe.lab.eng.bos.redhat.com pulp[28902]: celery.worker.job:ERROR: (28902-87040) MissingResource: Missing resource(s): repository=1234foo
Jan 29 10:0

el6

Jan 29 10:45:17 gizmo pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[d933ccd8-4d4b-49fd-b5fb-8f4ed251796c]
Jan 29 10:45:17 gizmo pulp: celery.worker.job:INFO: Task pulp.server.tasks.repository.sync_with_auto_publish[abdd1e8c-7a6d-4959-be32-6738ac2eb10e] succeeded in 116.79131452s: <pulp.server.async.tasks.TaskResult object at 0x26df450>