jgosmann / dmarc-metrics-exporter

Export Prometheus metrics from DMARC reports.
MIT License
42 stars 6 forks source link

Mail fetched but not processed #33

Closed fxy-afau closed 1 year ago

fxy-afau commented 1 year ago

Hello,

I'm trying to use the v0.7.0 exporter. The mail are fetched at startup but not processed, here is my log :

DEBUG:dmarc_metrics_exporter.imap_queue:7 messages to fetch.
DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'*', 1, b'FETCH',  ...
DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'*', 2, b'FETCH',  ...
DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'*', 3, b'FETCH',  ...
DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'*', 4, b'FETCH',  ...
DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'*', 5, b'FETCH',  ...
DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'*', 6, b'FETCH',  ...
DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'*', 7, b'FETCH',  ...
DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'a6', b'OK', b'FETCH completed.')
DEBUG:dmarc_metrics_exporter.imap_client:IMAP command 'b'a6'' completed with 'b'OK' b'FETCH completed.''
INFO:uvicorn.access:172.19.0.2:42960 - "GET /metrics HTTP/1.1" 200
INFO:uvicorn.access:172.19.0.2:42960 - "GET /metrics HTTP/1.1" 200
INFO:uvicorn.access:172.19.0.2:42960 - "GET /metrics HTTP/1.1" 200

It looks like the mails are fetched and never processed and never fetched again, they stay in the INBOX folder and only their flag change from unseen to seen. The program seem to be stuck.

Do you have any idea what is causing this issue ?

Antoine

jgosmann commented 1 year ago

I'd need some more information. Can you provide a complete "IMAP response" line. You may skip the message body and other sensitive information. My main question for now would be whether the UID and RFC822 fields are included. If not, the email will silently be skipped (I probably should add some more logging to make this case more easily diagnosable).

fxy-afau commented 1 year ago

Yes of course, here is the data for the last mail received, do you need all of them ?

DEBUG:dmarc_metrics_exporter.imap_client:IMAP response: (b'*', 7, b'FETCH', ((b'UID', 7), (b'RFC822', bytearray(b'Received: from EXC11009.exchange.local (XXX.XXX.XXX.XXX) by
 EXC01008.exchange.local (XXX.XXX.XXX.XXX) with Microsoft SMTP Server
 (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256_P256) id
 XXX.XXX.XXX.XXX via Mailbox Transport; Wed, 30 Nov 2022 12:09:41 +0100
Received: from EXC11001.exchange.local (XXX.XXX.XXX.XXX) by
 EXC11009.exchange.local (XXX.XXX.XXX.XXX) with Microsoft SMTP Server
 (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256_P256) id
 XXX.XXX.XXX.XXX; Wed, 30 Nov 2022 12:09:40 +0100
Received: from smt02001.gcompany.net (XXX.XXX.XXX.XXX) by
 EXC11001.exchange.local (XXX.XXX.XXX.XXX) with Microsoft SMTP Server id
 XXX.XXX.XXX.XXX via Frontend Transport; Wed, 30 Nov 2022 12:09:41 +0100
Received: from fx405.scompany.net (smtpout140.scompany.net [XXX.XXX.XXX.XXX])
    (using TLSv1.2 with cipher ADH-AES256-GCM-SHA384 (256/256 bits))
    (No client certificate requested)
    by smt02001.gcompany.net (Postfix) with ESMTPS id AC328DC28D1
    for <dmarc@company.com>; Wed, 30 Nov 2022 12:09:37 +0100 (CET)
Received: from localhost (fx405.scompany.net [XXX.XXX.XXX.XXX])
    by fx405.scompany.net (Postfix) with ESMTP id 99ADF335F17
    for <dmarc@company.com>; Wed, 30 Nov 2022 12:09:37 +0100 (CET)
Received: from fx405 (fx405.scompany.net [XXX.XXX.XXX.XXX]) by
 fx405.scompany.net (Postfix) with ESMTP id 3CEA9335EF2 for
 <dmarc@company.com>; Wed, 30 Nov 2022 12:09:37 +0100 (CET)
Received: from mail-qv1-f74.google.com (mail-qv1-f74.google.com
 [XXX.XXX.XXX.XXX]) by fx405.scompany.net (Postfix) with ESMTPS id
 45801335E4F for <dmarc@company.com>; Wed, 30 Nov 2022 12:09:36 +0100 (CET)
Received: by mail-qv1-f74.google.com with SMTP id
 nn2-20020a056214358200b004bb7bc3dfdcso25568832qvb.23 for <dmarc@company.com>;
 Wed, 30 Nov 2022 03:09:36 -0800 (PST)
From: "noreply-dmarc-support@google.com" <noreply-dmarc-support@google.com>
To: DMARC company <dmarc@company.com>
Subject: Report domain: company.com Submitter: google.com Report-ID:
 2130603631942569115
Thread-Topic: Report domain: company.com Submitter: google.com Report-ID:
 2130603631942569115
Thread-Index: AQHZBKw+oJaUkb1UnESOTdssn+no5w==
X-MS-Exchange-MessageSentRepresentingType: 1
Date: Wed, 30 Nov 2022 00:59:59 +0100
Message-ID: <2130603631942569115@google.com>
Content-Language: fr-FR
X-MS-Exchange-Organization-AuthAs: Anonymous
X-MS-Exchange-Organization-AuthSource: EXC11001.exchange.local
X-MS-Has-Attach: yes
X-MS-Exchange-Organization-Network-Message-Id:
    b1dae67e-5846-47d7-4c3c-08dad2c360d6
X-MS-TNEF-Correlator:
X-MS-Exchange-Organization-RecordReviewCfmType: 0
authentication-results: fx405.scompany.net (amavisd-new); dkim=pass
 (2048-bit key) header.d=google.com
x-global-asp-net-mailscanner-id: AC328DC28D1.AE5CC
dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com;
 s=20210112; h=content-transfer-encoding:content-disposition:to:from:subject
 :message-id:date:mime-version:from:to:cc:subject:date:message-id :reply-to;
 bh=fDt6/x89B7DUsC+2YJzGLWmQ58iHwiOnpxh7aH3Efjo=;
 b=eMjdL9nvvLioP+TGKCRO8t+kt555HBDoRkJaKU29ACYitTKebrCVVYwIVdLtSKKBeH
 2ylXCFH/dUqmIX1wG1EJS2B3uQPHHBisub3dkBEbRvlasNi1HuzCK4SCfg4RTTNDlLpC
 IA+qiuNHn4OJtExZ4uC4HXu7mUTB8AHrY7Kyd73btdNdeHdCwqFFugkdafqbGucTNbb4
 nxbT8eTiXnZvCO/YlpFCaKfTMl01kLnQ/aNMzLJg53QoVZesLP8vFaMwmZXFhdvc+6Tc
 kEKZwZMVDccifULY10CVBv2Rl7GpQXQN6npu3VrgnIKFpZeAS19aijoHkyF00jLkemsu cJAQ==
x-mailscanner-from: noreply-dmarc-support@google.com
x-global-asp-net-mailscanner-spamcheck: not spam, SpamAssassin (not cached,
    score=3.479, required 5, autolearn=disabled, DATE_IN_PAST_06_12 1.10,
    DKIM_ADSP_CUSTOM_MED 0.00, DKIM_INVALID 0.10, DKIM_SIGNED 0.10,
    KHOP_HELO_FCRDNS 0.00, NML_ADSP_CUSTOM_MED 1.20, SPF_HELO_NONE 0.00,
    SPF_SOFTFAIL 0.97, TVD_SPACE_RATIO 0.00)
x-global-asp-net-mailscanner: Found to be clean
x-global-asp-net-mailscanner-spamscore: sss
x-spam-status: No, score=-16.186 tagged_above=-1000 required=5
 tests=[AB_LONG_SUBJ_30=0.001, AB_REAL_ATTACHMENT=-0.5, BO_CD_ATTACH=0.0001,
 BO_HUMAIL_SINGLE_LINK=0.0001, DATE_IN_PAST_06_12=1.103, DKIMWL_WL_MED=-0.001,
 DKIM_SIGNED=0.1, DKIM_VALID=-1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1,
 DMARC_REJECT=0.3, ENV_AND_HDR_SPF_MATCH=-0.5, MM_NO_REAL_NAME2=0.01,
 RCVD_IN_DNSWL_NONE=-0.0001, RCVD_IN_MSPIKE_H2=-0.5, SPF_HELO_NONE=0.001,
 SPF_PASS=-0.001, TVD_SPACE_RATIO=0.001, USER_IN_DEF_DKIM_WL=-7.5,
 USER_IN_DEF_SPF_WL=-7.5] autolearn=disabled
x-received: by ipv6 with SMTP id
 t17-20020ac86a11000000b003a50933e8a9mr57348070qtr.676.1669806575370; Wed, 30
 Nov 2022 03:09:35 -0800 (PST)
x-google-dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net;
 s=20210112; h=content-transfer-encoding:content-disposition:to:from:subject
 :message-id:date:mime-version:x-gm-message-state:from:to:cc:subject
 :date:message-id:reply-to; bh=fDt6/x89B7DUsC+2YJzGLWmQ58iHwiOnpxh7aH3Efjo=;
 b=B4UcBcyN/097Q8DYgGwzLI4oUvJdFhiAF4PPV54nyUwoYwFWpI/VHRX/ytsAxUZTlo
 Kv2ZepaT4X0o7qdwW4RdXeYKziZP1D61kbhkArmMhxuB8yz7Kc6+3E/SpRQ+SZLgpAG4
 I36+1m1lhChfn5WbKb1JAHYWJPF6bF6lyQCaWtRS5oReuqJG5/msxymynrRu9XKwjphS
 wMpZ6N+ShzrYAu5dSGfkD6ygzCPH041m2nW6HXZ0HMWrTGW+avLjLRTV5C4bPn8JidSq
 LxovKMTHku8YZR53d9qggc6YVu10CZxrurXI7saq9epDMicxlgeDlcBuVaCi9ql6DVNf suMw==
x-gm-message-state: ANoB5pm/mPZiQmtGF0Gsl6SsedtbbsmiHImuK/yjTz80oj/u38ZAuQpV
 v5ARcj4pAE4Q37WanJ1v3A==
Content-Type: multipart/mixed; boundary="_002_2130603631942569115googlecom_"
MIME-Version: 1.0

--_002_2130603631942569115googlecom_
Content-Type: text/plain; charset="utf-8"
Content-ID: <0A8D97077210BC49A9E2D56A7B889978@exchange.local>
Content-Transfer-Encoding: base64

IA0KDQo=

--_002_2130603631942569115googlecom_
Content-Type: application/zip;
    name="google.com!company.com!1669680000!1669766399.zip"
Content-Description: google.com!company.com!1669680000!1669766399.zip
Content-Disposition: attachment;
    filename="google.com!company.com!1669680000!1669766399.zip"; size=2608;
    creation-date="Wed, 30 Nov 2022 11:09:41 GMT";
    modification-date="Wed, 30 Nov 2022 11:09:41 GMT"
Content-ID: <444AE839DCA6CD4AA9CC7A6BB7E55AF1@exchange.local>
Content-Transfer-Encoding: base64

[data]

--_002_2130603631942569115googlecom_--
')), (b'FLAGS', (b'\\Seen',))))

After that if I add new mails in the INBOX they are never processed.

jgosmann commented 1 year ago

Unfortunately, I still do not see what is causing the problem. The output looks like I would expect. Thus, I added some more logging and released version v0.8.0. Can you try and post logs from that one? I do not need the full emails for now, but any of the following messages would be useful to determine where exactly the processing hangs:

fxy-afau commented 1 year ago

After upgrading to v0.8.0 the logs show this line only : Failed to extract RFC822 message for message 1 (UID 16)

jgosmann commented 1 year ago

I think I finally found the issue. Can you try release v0.8.1 and see if it works now?

fxy-afau commented 1 year ago

It works ! Thank you.