Skip to content

Conversation

sduenas
Copy link
Member

@sduenas sduenas commented Jun 30, 2025

Organizing log data in a structured format makes easier to read and analyze them.

With this PR, log messages will always have a structured format. The default mode is to print the messages to the
console in a plain format, but it can also be configured to print them in JSON format.

We have added structured logs to GrimoireLab using the 'structlog' package.

@sduenas sduenas requested a review from jjmerchante June 30, 2025 21:26
@sduenas sduenas force-pushed the structlog branch 2 times, most recently from 381a613 to 0f63865 Compare July 3, 2025 19:49
Organizing log data in a structured format makes easier
to read and analyze them.

With this commit, log messages will always have a structured
format. The default mode is to print the messages to the
console in a plain format, but it can also be configured
to print them in JSON format.

We have added structured logs to GrimoireLab using the
'structlog' package.

By default, tests will run silent. If developers want to get
log messages printed to the console, activate the environment
variable 'GRIMOIRELAB_TESTING_VERBOSE'.

Signed-off-by: Santiago Dueñas <[email protected]>
Some messages were updated to follow the structured format.

Signed-off-by: Santiago Dueñas <[email protected]>
Copy link
Contributor

@jjmerchante jjmerchante left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I include some comments about the handlers and future improvements.

task = job_db.task

logger.error(f"Job #{job_db.job_id} (task: {task.task_id}) failed; error: {value}")
logger.info("job failed", job_uuid=job_db.uuid, task_uuid=task.uuid, error=value)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All the logs in _on_failure_callback use info. Shouldn’t they be error instead, for easier filtering?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I though of it but I wasn't sure because a failed job doesn't implies an error in the platform but probably, for filtering, it will be easier to get them. I'll change it.

consumer.start(burst=burst)
except Exception as e:
logging.error(f"Consumer {consumer_class.__name__} failed: {e}")
logger.error(f"Consumer {consumer_class.__name__} failed: {e}")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
logger.error(f"Consumer {consumer_class.__name__} failed: {e}")
logger.error(f"Consumer {consumer_class.__name__} failed", exc_info=ex)

"django.middleware.csrf.CsrfViewMiddleware",
"django.contrib.auth.middleware.AuthenticationMiddleware",
"django.contrib.messages.middleware.MessageMiddleware",
"django.middleware.clickjacking.XFrameOptionsMiddleware",
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If, at some point, we want to use a handler to store the logs somewhere, we might need to consider using the middleware, or if we suppress the uwsgi logs we can also use it.

Suggested change
"django.middleware.clickjacking.XFrameOptionsMiddleware",
"django_structlog.middlewares.RequestMiddleware",
]

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll add it.

Comment on lines +159 to +160
"grimoirelab.core.scheduler": {
"handlers": ["scheduler"],
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There are 2 handlers for the module grimoirelab.core.scheduler, and messages are duplicated. But I don't understand why it is json format and not not_structured, but if I disable the second line I only get the default handler.

[2025-10-10 10:37:38,664 - grimoirelab.core.scheduler.scheduler - INFO] - {'job_uuid': 'e6dfc352-4a71-421c-a4a3-3ee6260caba7', 'job_args': {'datasource_type': 'git', 'datasource_category': 'commit', 'events_stream': 'events', 'stream_max_length': 1000000, 'job_args': {'latest_items': False, 'gitpath': '/home/jjmerchante/.perceval/https://github.com/chaoss/grimoirelab-perceval.git-git', 'uri': 'https://github.com/chaoss/grimoirelab-perceval.git'}}, 'task_uuid': 'd8d499db-4458-4ae2-839f-b06c0ed1bef8', 'queue': 'eventizer_jobs', 'scheduled_at': datetime.datetime(2025, 10, 10, 10, 37, 38, 648956, tzinfo=datetime.timezone.utc), 'event': 'job scheduled', 'timestamp': '2025-10-10T10:37:38.664211Z', 'level': 'info', 'logger': 'grimoirelab.core.scheduler.scheduler'}
2025-10-10T10:37:38.664211Z [info     ] [grimoirelab.core.scheduler.scheduler] job scheduled job_args={'datasource_type': 'git', 'datasource_category': 'commit', 'events_stream': 'events', 'stream_max_length': 1000000, 'job_args': {'latest_items': False, 'gitpath': '/home/jjmerchante/.perceval/https://github.com/chaoss/grimoirelab-perceval.git-git', 'uri': 'https://github.com/chaoss/grimoirelab-perceval.git'}} job_uuid=e6dfc352-4a71-421c-a4a3-3ee6260caba7 queue=eventizer_jobs scheduled_at=2025-10-10 10:37:38.648956+00:00 task_uuid=d8d499db-4458-4ae2-839f-b06c0ed1bef

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants