Sidekiq current log contains non-json garbage

Summary

Sidekiq's current log /var/log/gitlab/sidekiq/current contains various garbage so it is not valid JSON. Quick example:

jq < /var/log/gitlab/sidekiq/current

{
  "severity": "INFO",
  "time": "2022-03-10T13:36:14.314Z",
  "message": "Starting cluster with 1 processes"
}

parse error: Invalid numeric literal at line 2, column 14

It is because line 2 contains non-json line:

2022-03-10T13:36:37.378Z pid=15345 tid=j0p INFO: Listening on queues ["analytics...

Steps to reproduce

Tested on openSUSE LEAP 15.3

  1. Install latest GitLab CE for SUSE, tested gitlab-ce-14.8.2-ce.0.sles15.x86_64
  2. Verify that GitLab is properly installed and running (no other setup is necessary)
  3. Try to parse /var/log/gitlab/sidekiq/current with jq tool using:
    jq < /var/log/gitlab/sidekiq/current
  4. It will crash right on second line, with error:
    parse error: Invalid numeric literal at line 2, column 14
  5. It is because there is plain text message on line 2 instead of JSON

What is the current bug behavior?

The /var/log/gitlab/sidekiq/current which is supposed to be valid JSON is interleaved with various plain-text messages that are NOT json compatible and thus we are unable to parse them as JSON (for reporting, monitoring, etc.)

The full command is:

jq < /var/log/gitlab/sidekiq/current

{
  "severity": "INFO",
  "time": "2022-03-10T13:36:14.314Z",
  "message": "Starting cluster with 1 processes"
}
parse error: Invalid numeric literal at line 2, column 14

Example invalid non-json entries found with grep and sed:

egrep -v '^\{' /var/log/gitlab/sidekiq/current  | sed  -E 's/^(.{80}).*/\1/'

2022-03-10T13:36:37.378Z pid=15345 tid=j0p INFO: Listening on queues ["analytics
sendmail: warning: ICU library initialization failed: U_FILE_ACCESS_ERROR
2022-03-10T14:01:26.327Z pid=3063 tid=fv3 INFO: Listening on queues ["analytics_

There are 3 non-json entries so far.

What is the expected correct behavior?

The log file /var/log/gitlab/sidekiq/current should containe only vaild JSON output.

Relevant logs and/or screenshots

Here are few to lines from current log (very long)

{"severity":"INFO","time":"2022-03-10T13:36:14.314Z","message":"Starting cluster with 1 processes"}
2022-03-10T13:36:37.378Z pid=15345 tid=j0p INFO: Listening on queues ["analytics_usage_trends_counter_job", "approve_blocked_pending_approval_users", "authorized_keys", "authorized_project_update:authorized_project_update_project_create", "authorized_project_update:authorized_project_update_project_group_link_create", "authorized_project_update:authorized_project_update_project_recalculate", "authorized_project_update:authorized_project_update_project_recalculate_per_user", "authorized_project_update:authorized_project_update_user_refresh_from_replica", "authorized_project_update:authorized_project_update_user_refresh_over_user_range", "authorized_project_update:authorized_project_update_user_refresh_with_low_urgency", "authorized_projects", "auto_devops:auto_devops_disable", "auto_merge:auto_merge_process", "background_migration", "background_migration_ci_database", "bulk_import", "bulk_imports_entity", "bulk_imports_export_request", "bulk_imports_pipeline", "bulk_imports_relation_export", "chaos:chaos_cpu_spin", "chaos:chaos_db_spin", "chaos:chaos_kill", "chaos:chaos_leak_mem", "chaos:chaos_sleep", "chat_notification", "ci_delete_objects", "ci_job_artifacts_expire_project_build_artifacts", "cluster_agent:clusters_agents_delete_expired_events", "container_repository:cleanup_container_repository", "container_repository:container_expiration_policies_cleanup_container_repository", "container_repository:delete_container_repository", "create_commit_signature", "create_note_diff_file", "cronjob:admin_email", "cronjob:analytics_usage_trends_count_job_trigger", "cronjob:authorized_project_update_periodic_recalculate", "cronjob:ci_archive_traces_cron", "cronjob:ci_delete_unit_tests", "cronjob:ci_pipeline_artifacts_expire_artifacts", "cronjob:ci_platform_metrics_update_cron", "cronjob:ci_schedule_delete_objects_cron", "cronjob:ci_stuck_builds_drop_running", "cronjob:ci_stuck_builds_drop_scheduled", "cronjob:clusters_integrations_check_prometheus_health", "cronjob:container_expiration_policy", "cronjob:container_registry_migration_enqueuer", "cronjob:container_registry_migration_guard", "cronjob:container_registry_migration_observer", "cronjob:database_batched_background_migration", "cronjob:database_drop_detached_partitions", "cronjob:database_partition_management", "cronjob:dependency_proxy_cleanup_dependency_proxy", "cronjob:dependency_proxy_image_ttl_group_policy", "cronjob:environments_auto_delete_cron", "cronjob:environments_auto_stop_cron", "cronjob:expire_build_artifacts", "cronjob:gitlab_service_ping", "cronjob:import_export_project_cleanup", "cronjob:import_stuck_project_import_jobs", "cronjob:issue_due_scheduler", "cronjob:issues_reschedule_stuck_issue_rebalances", "cronjob:jira_import_stuck_jira_import_jobs", "cronjob:loose_foreign_keys_cleanup", "cronjob:member_invitation_reminder_emails", "cronjob:metrics_dashboard_schedule_annotations_prune", "cronjob:namespaces_in_product_marketing_emails", "cronjob:namespaces_prune_aggregation_schedules", "cronjob:packages_cleanup_package_registry", "cronjob:packages_composer_cache_cleanup", "cronjob:pages_domain_removal_cron", "cronjob:pages_domain_ssl_renewal_cron", "cronjob:pages_domain_verification_cron", "cronjob:partition_creation", "cronjob:personal_access_tokens_expired_notification", "cronjob:personal_access_tokens_expiring", "cronjob:pipeline_schedule", "cronjob:prune_old_events", "cronjob:releases_manage_evidence", "cronjob:remove_expired_group_links", "cronjob:remove_expired_members", "cronjob:remove_unaccepted_member_invites", "cronjob:remove_unreferenced_lfs_objects", "cronjob:repository_archive_cache", "cronjob:repository_check_dispatch", "cronjob:requests_profiles", "cronjob:schedule_merge_request_cleanup_refs", "cronjob:schedule_migrate_external_diffs", "cronjob:ssh_keys_expired_notification", "cronjob:ssh_keys_expiring_soon_notification", "cronjob:stuck_ci_jobs", "cronjob:stuck_export_jobs", "cronjob:stuck_merge_jobs", "cronjob:trending_projects", "cronjob:update_container_registry_info", "cronjob:user_status_cleanup_batch", "cronjob:users_create_statistics", "cronjob:users_deactivate_dormant_users", "cronjob:x509_issuer_crl_check", "default", "delete_diff_files", "delete_merged_branches", "delete_stored_files", "delete_user", "dependency_proxy:purge_dependency_proxy_cache", "dependency_proxy_blob:dependency_proxy_cleanup_blob", "dependency_proxy_manifest:dependency_proxy_cleanup_manifest", "deployment:deployments_archive_in_project", "deployment:deployments_drop_older_deployments", "deployment:deployments_hooks", "deployment:deployments_link_merge_request", "deployment:deployments_update_environment", "design_management_copy_design_collection", "design_management_new_version", "destroy_pages_deployments", "detect_repository_languages", "disallow_two_factor_for_group", "disallow_two_factor_for_subgroups", "email_receiver", "emails_on_push", "environments_auto_stop", "environments_canary_ingress_update", "error_tracking_issue_link", "experiments_record_conversion_event", "expire_build_instance_artifacts", "export_csv", "external_service_reactive_caching", "file_hook", "flush_counter_increments", "gcp_cluster:cluster_configure_istio", "gcp_cluster:cluster_install_app", "gcp_cluster:cluster_patch_app", "gcp_cluster:cluster_provision", "gcp_cluster:cluster_update_app", "gcp_cluster:cluster_upgrade_app", "gcp_cluster:cluster_wait_for_app_installation", "gcp_cluster:cluster_wait_for_app_update", "gcp_cluster:cluster_wait_for_ingress_ip_address", "gcp_cluster:clusters_applications_activate_service", "gcp_cluster:clusters_applications_deactivate_service", "gcp_cluster:clusters_applications_uninstall", "gcp_cluster:clusters_applications_wait_for_uninstall_app", "gcp_cluster:clusters_cleanup_project_namespace", "gcp_cluster:clusters_cleanup_service_account", "gcp_cluster:wait_for_cluster_creation", "github_import_advance_stage", "github_importer:github_import_import_diff_note", "github_importer:github_import_import_issue", "github_importer:github_import_import_lfs_object", "github_importer:github_import_import_note", "github_importer:github_import_import_pull_request", "github_importer:github_import_import_pull_request_merged_by", "github_importer:github_import_import_pull_request_review", "github_importer:github_import_refresh_import_jid", "github_importer:github_import_stage_finish_import", "github_importer:github_import_stage_import_base_data", "github_importer:github_import_stage_import_issues_and_diff_notes", "github_importer:github_import_stage_import_lfs_objects", "github_importer:github_import_stage_import_notes", "github_importer:github_import_stage_import_pull_requests", "github_importer:github_import_stage_import_pull_requests_merged_by", "github_importer:github_import_stage_import_pull_requests_reviews", "github_importer:github_import_stage_import_repository", "gitlab_performance_bar_stats", "gitlab_shell", "group_destroy", "group_export", "group_import", "groups_update_statistics", "hashed_storage:hashed_storage_migrator", "hashed_storage:hashed_storage_project_migrate", "hashed_storage:hashed_storage_project_rollback", "hashed_storage:hashed_storage_rollbacker", "import_issues_csv", "incident_management:incident_management_add_severity_system_note", "incident_management:incident_management_pager_duty_process_incident", "incident_management:incident_management_process_alert_worker_v2", "integrations_create_external_cross_reference", "invalid_gpg_signature_update", "irker", "issuable_export_csv", "issuable_label_links_destroy", "issuables_clear_groups_issue_counter", "issue_placement", "issue_rebalancing", "issues_placement", "issues_rebalancing", "jira_connect:jira_connect_forward_event", "jira_connect:jira_connect_retry_request", "jira_connect:jira_connect_sync_branch", "jira_connect:jira_connect_sync_builds", "jira_connect:jira_connect_sync_deployments", "jira_connect:jira_connect_sync_feature_flags", "jira_connect:jira_connect_sync_merge_request", "jira_connect:jira_connect_sync_project", "jira_importer:jira_import_advance_stage", "jira_importer:jira_import_import_issue", "jira_importer:jira_import_stage_finish_import", "jira_importer:jira_import_stage_import_attachments", "jira_importer:jira_import_stage_import_issues", "jira_importer:jira_import_stage_import_labels", "jira_importer:jira_import_stage_import_notes", "jira_importer:jira_import_stage_start_import", "mail_scheduler:mail_scheduler_issue_due", "mail_scheduler:mail_scheduler_notification_service", "mailers", "merge", "merge_request_cleanup_refs", "merge_request_mergeability_check", "merge_requests_delete_source_branch", "merge_requests_handle_assignees_change", "merge_requests_resolve_todos", "merge_requests_update_head_pipeline", "metrics_dashboard_prune_old_annotations", "metrics_dashboard_sync_dashboards", "migrate_external_diffs", "namespaceless_project_destroy", "namespaces_invite_team_email", "namespaces_onboarding_issue_created", "namespaces_onboarding_pipeline_created", "namespaces_onboarding_progress", "namespaces_onboarding_user_added", "namespaces_process_sync_events", "namespaces_update_root_statistics", "new_issue", "new_merge_request", "new_note", "object_pool:object_pool_create", "object_pool:object_pool_destroy", "object_pool:object_pool_join", "object_pool:object_pool_schedule_join", "object_storage:object_storage_background_move", "object_storage:object_storage_migrate_uploads", "package_cleanup:packages_cleanup_package_file", "package_cleanup:packages_mark_package_files_for_destruction", "package_repositories:packages_debian_generate_distribution", "package_repositories:packages_debian_process_changes", "package_repositories:packages_go_sync_packages", "package_repositories:packages_helm_extraction", "package_repositories:packages_maven_metadata_sync", "package_repositories:packages_nuget_extraction", "package_repositories:packages_rubygems_extraction", "packages_composer_cache_update", "pages", "pages_domain_ssl_renewal", "pages_domain_verification", "pages_transfer", "phabricator_import_import_tasks", "pipeline_background:archive_trace", "pipeline_background:ci_archive_trace", "pipeline_background:ci_build_trace_chunk_flush", "pipeline_background:ci_daily_build_group_report_results", "pipeline_background:ci_pending_builds_update_group", "pipeline_background:ci_pending_builds_update_project", "pipeline_background:ci_pipeline_artifacts_coverage_report", "pipeline_background:ci_pipeline_artifacts_create_quality_report", "pipeline_background:ci_pipeline_success_unlock_artifacts", "pipeline_background:ci_ref_delete_unlock_artifacts", "pipeline_background:ci_test_failure_history", "pipeline_cache:expire_job_cache", "pipeline_cache:expire_pipeline_cache", "pipeline_creation:ci_external_pull_requests_create_pipeline", "pipeline_creation:create_pipeline", "pipeline_creation:merge_requests_create_pipeline", "pipeline_creation:run_pipeline_schedule", "pipeline_default:ci_create_cross_project_pipeline", "pipeline_default:ci_create_downstream_pipeline", "pipeline_default:ci_drop_pipeline", "pipeline_default:ci_merge_requests_add_todo_when_build_fails", "pipeline_default:ci_pipeline_bridge_status", "pipeline_default:ci_retry_pipeline", "pipeline_default:pipeline_metrics", "pipeline_default:pipeline_notification", "pipeline_hooks:build_hooks", "pipeline_hooks:pipeline_hooks", "pipeline_processing:build_finished", "pipeline_processing:build_queue", "pipeline_processing:build_success", "pipeline_processing:ci_build_finished", "pipeline_processing:ci_build_prepare", "pipeline_processing:ci_build_schedule", "pipeline_processing:ci_initial_pipeline_process", "pipeline_processing:ci_resource_groups_assign_resource_from_resource_group", "pipeline_processing:pipeline_process", "pipeline_processing:stage_update", "pipeline_processing:update_head_pipeline_for_merge_request", "post_receive", "process_commit", "project_cache", "project_daily_statistics", "project_destroy", "project_export", "project_service", "projects_git_garbage_collect", "projects_post_creation", "projects_process_sync_events", "projects_schedule_bulk_repository_shard_moves", "projects_update_repository_storage", "prometheus_create_default_alerts", "propagate_integration", "propagate_integration_group", "propagate_integration_inherit", "propagate_integration_inherit_descendant", "propagate_integration_project", "reactive_caching", "rebase", "releases_create_evidence", "remote_mirror_notification", "repository_check:repository_check_batch", "repository_check:repository_check_clear", "repository_check:repository_check_single_repository", "repository_cleanup", "repository_fork", "repository_import", "repository_remove_remote", "repository_update_remote_mirror", "self_monitoring_project_create", "self_monitoring_project_delete", "service_desk_email_receiver", "snippets_schedule_bulk_repository_shard_moves", "snippets_update_repository_storage", "system_hook_push", "tasks_to_be_done_create", "todos_destroyer:todos_destroyer_confidential_issue", "todos_destroyer:todos_destroyer_destroyed_designs", "todos_destroyer:todos_destroyer_destroyed_issuable", "todos_destroyer:todos_destroyer_entity_leave", "todos_destroyer:todos_destroyer_group_private", "todos_destroyer:todos_destroyer_private_features", "todos_destroyer:todos_destroyer_project_private", "unassign_issuables:members_destroyer_unassign_issuables", "update_external_pull_requests", "update_highest_role", "update_merge_requests", "update_namespace_statistics:namespaces_root_statistics", "update_namespace_statistics:namespaces_schedule_aggregation", "update_project_statistics", "upload_checksum", "web_hook", "web_hooks_destroy", "web_hooks_log_execution", "wikis_git_garbage_collect", "x509_certificate_revoke"]
{"severity":"INFO","time":"2022-03-10T13:36:37.382Z","message":"Booting Sidekiq 6.4.0 with redis options {:instrumentation_class=\u003eGitlab::Instrumentation::Redis::Queues, :path=\u003e\"/var/opt/gitlab/redis/redis.socket\", :namespace=\u003e\"resque:gitlab\"}"}

Output of checks

Results of GitLab environment info

Output of OS Release /etc/os-release:

NAME="openSUSE Leap"
VERSION="15.3"
ID="opensuse-leap"
ID_LIKE="suse opensuse"
VERSION_ID="15.3"
PRETTY_NAME="openSUSE Leap 15.3"
ANSI_COLOR="0;32"
CPE_NAME="cpe:/o:opensuse:leap:15.3"
BUG_REPORT_URL="https://bugs.opensuse.org"
HOME_URL="https://www.opensuse.org/"

This official Omnibus RPM package was installed:

rpm -qi gitlab-ce
Name        : gitlab-ce
Version     : 14.8.2
Release     : ce.0.sles15
Architecture: x86_64
Install Date: Thu Mar 10 14:33:15 2022
Group       : default
Size        : 2243292390
License     : MIT
Signature   : RSA/SHA256, Fri Feb 25 21:27:49 2022, Key ID 3cfcf9baf27eab47
Source RPM  : gitlab-ce-14.8.2-ce.0.sles15.src.rpm
Build Date  : Fri Feb 25 21:22:11 2022
Build Host  : runner-d1f91b99-project-283-concurrent-0
Relocations : /
Packager    : GitLab, Inc. <support@gitlab.com>
Vendor      : GitLab, Inc. <support@gitlab.com>
URL         : https://about.gitlab.com/
Summary     : GitLab Community Edition (including NGINX, Postgres, Redis)
Description :
GitLab Community Edition (including NGINX, Postgres, Redis)
Distribution: (none)

Results of GitLab application Check

N/A

Possible fixes

N/A