diff --git a/cloudinit/analyze/dump.py b/cloudinit/analyze/dump.py index 63aab904a39..67ee49cc41f 100644 --- a/cloudinit/analyze/dump.py +++ b/cloudinit/analyze/dump.py @@ -1,12 +1,15 @@ # This file is part of cloud-init. See LICENSE file for license information. import calendar +import logging import sys from datetime import datetime, timezone from typing import IO, Any, Dict, List, Optional, TextIO, Tuple from cloudinit import atomic_helper, subp, util +LOG = logging.getLogger(__name__) + stage_to_description: Dict[str, str] = { "finished": "finished running cloud-init", "init-local": "starting search for local datasources", @@ -76,6 +79,16 @@ def parse_timestamp_from_date(timestampstr: str) -> float: raise ValueError( f"Unable to parse timestamp without GNU date: [{timestampstr}]" ) + # Transitional: shelling out to GNU date is slated for removal in favor of + # native Python parsing. Log the unrecognized timestamp so maintainers can + # collect formats that need direct support (see GH-4357). + LOG.warning( + "analyze: falling back to GNU %s(1) to parse unrecognized " + "timestamp %r; please report this format upstream so it can be " + "handled natively in Python.", + date, + timestampstr, + ) return float( subp.subp([date, "-u", "+%s.%3N", "-d", timestampstr]).stdout.strip() ) diff --git a/tests/unittests/analyze/test_dump.py b/tests/unittests/analyze/test_dump.py index 45bf1c743e4..9fe96f6acb0 100644 --- a/tests/unittests/analyze/test_dump.py +++ b/tests/unittests/analyze/test_dump.py @@ -1,5 +1,6 @@ # This file is part of cloud-init. See LICENSE file for license information. +import logging import warnings from contextlib import suppress from datetime import datetime, timezone @@ -13,7 +14,9 @@ has_gnu_date, parse_ci_logline, parse_timestamp, + parse_timestamp_from_date, ) +from cloudinit.subp import SubpResult from cloudinit.util import write_file @@ -112,6 +115,61 @@ def test_parse_timestamp_handles_explicit_timezone(self): == "2020-09-12 12:39:20" ) + @mock.patch("cloudinit.analyze.dump.subp.subp") + @mock.patch("cloudinit.analyze.dump.has_gnu_date", return_value=True) + @mock.patch("cloudinit.analyze.dump.util.is_Linux", return_value=True) + def test_parse_timestamp_from_date_warns_on_gnu_date_fallback( + self, _m_is_linux, _m_has_gnu, m_subp, caplog + ): + """A warning is emitted whenever GNU date(1) is used as a fallback.""" + m_subp.return_value = SubpResult("1597333950.000\n", "") + timestampstr = "17:15 08/13" + with caplog.at_level(logging.WARNING, logger="cloudinit.analyze.dump"): + assert 1597333950.0 == parse_timestamp_from_date(timestampstr) + m_subp.assert_called_once_with( + ["date", "-u", "+%s.%3N", "-d", timestampstr] + ) + warnings_logged = [ + r for r in caplog.records if r.levelname == "WARNING" + ] + assert 1 == len(warnings_logged) + assert "date(1)" in warnings_logged[0].getMessage() + assert repr(timestampstr) in warnings_logged[0].getMessage() + + @mock.patch("cloudinit.analyze.dump.subp.which", return_value="/bin/gdate") + @mock.patch("cloudinit.analyze.dump.subp.subp") + @mock.patch("cloudinit.analyze.dump.has_gnu_date", return_value=False) + @mock.patch("cloudinit.analyze.dump.util.is_Linux", return_value=False) + def test_parse_timestamp_from_date_warns_on_gdate_fallback( + self, _m_is_linux, _m_has_gnu, m_subp, _m_which, caplog + ): + """The warning identifies gdate when used on non-Linux systems.""" + m_subp.return_value = SubpResult("1597333950.000\n", "") + timestampstr = "17:15 08/13" + with caplog.at_level(logging.WARNING, logger="cloudinit.analyze.dump"): + parse_timestamp_from_date(timestampstr) + m_subp.assert_called_once_with( + ["gdate", "-u", "+%s.%3N", "-d", timestampstr] + ) + warnings_logged = [ + r for r in caplog.records if r.levelname == "WARNING" + ] + assert 1 == len(warnings_logged) + assert "gdate(1)" in warnings_logged[0].getMessage() + assert repr(timestampstr) in warnings_logged[0].getMessage() + + @mock.patch("cloudinit.analyze.dump.subp.which", return_value=None) + @mock.patch("cloudinit.analyze.dump.has_gnu_date", return_value=False) + @mock.patch("cloudinit.analyze.dump.util.is_Linux", return_value=True) + def test_parse_timestamp_from_date_no_warning_when_no_gnu_date( + self, _m_is_linux, _m_has_gnu, _m_which, caplog + ): + """No warning is logged when there is no GNU date to fall back to.""" + with caplog.at_level(logging.WARNING, logger="cloudinit.analyze.dump"): + with pytest.raises(ValueError): + parse_timestamp_from_date("17:15 08/13") + assert [] == [r for r in caplog.records if r.levelname == "WARNING"] + class TestParseCILogLine: def test_parse_logline_returns_none_without_separators(self): @@ -222,15 +280,13 @@ def test_parse_logline_returns_event_for_amazon_linux_2_line(self): assert expected == parse_ci_logline(line) -SAMPLE_LOGS = dedent( - """\ +SAMPLE_LOGS = dedent("""\ Nov 03 06:51:06.074410 x2 cloud-init[106]: [CLOUDINIT] util.py[DEBUG]:\ Cloud-init v. 0.7.8 running 'init-local' at Thu, 03 Nov 2016\ 06:51:06 +0000. Up 1.0 seconds. 2016-08-30 21:53:25.972325+00:00 y1 [CLOUDINIT] handlers.py[DEBUG]: finish:\ modules-final: SUCCESS: running modules for final -""" -) +""") class TestDumpEvents: