Logging: Fix tests.

[busunkim96]

Fixes internal issue 134713268.

[bmccutchon]

I think you need to also change the usage to datetime.datetime.utcfromtimestamp to fix the build.

[tseaver]

Also, we need to figure out why #8227 passed CI here.

[busunkim96]

@tseaver We forgot to add kokoro: force-run on that PR.

[busunkim96]

Looks like there's some more work to get tests passing again (after fixing the import)

self = <google.cloud.logging.handlers.transports.background_thread._Worker object at 0x7f48d3fd15f8>

    def _thread_main(self):
        """The entry point for the worker thread.
    
        Pulls pending log entries off the queue and writes them in batches to
        the Cloud Logger.
        """
        _LOGGER.debug("Background thread started.")
    
        done = False
        while not done:
            batch = self._cloud_logger.batch()
            items = _get_many(
                self._queue,
                max_items=self._max_batch_size,
                max_latency=self._max_latency,
            )
    
            for item in items:
                if item is _WORKER_TERMINATOR:
                    done = True  # Continue processing items.
                else:
>                   batch.log_struct(**item)
E                   TypeError: log_struct() got an unexpected keyword argument 'timestamp'

google/cloud/logging/handlers/transports/background_thread.py:148: TypeError

[tseaver]

I don't understand the TypeError. Batch.log_struct is a straightforward wrapper:

google-cloud-python/logging/google/cloud/logging/logger.py

Lines 338 to 348 in c5acdad

	def log_struct(self, info, **kw):
	"""Add a struct entry to be logged during :meth:`commit`.
	:type info: dict
	:param info: the struct entry
	:type kw: dict
	:param kw: (optional) additional keyword arguments for the entry.
	See :class:`~google.cloud.logging.entries.LogEntry`.
	"""
	self.entries.append(StructEntry(payload=info, **kw))

creating a StructEntry

google-cloud-python/logging/google/cloud/logging/entries.py

Line 295 in c5acdad

class StructEntry(LogEntry):

which derives from LogEntry:

google-cloud-python/logging/google/cloud/logging/entries.py

Line 147 in c5acdad

class LogEntry(_LogEntryTuple):

which derives from _LogEntryTuple:

google-cloud-python/logging/google/cloud/logging/entries.py

Lines 67 to 87 in c5acdad

	_LOG_ENTRY_FIELDS = ( # (name, default)
	("log_name", None),
	("labels", None),
	("insert_id", None),
	("severity", None),
	("http_request", None),
	("timestamp", None),
	("resource", _GLOBAL_RESOURCE),
	("trace", None),
	("span_id", None),
	("trace_sampled", None),
	("source_location", None),
	("operation", None),
	("logger", None),
	("payload", None),
	)
	_LogEntryTuple = collections.namedtuple(
	"LogEntry", (field for field, _ in _LOG_ENTRY_FIELDS)
	)

which clearly takes a timestamp.

[tseaver]

OK, the batch in this case is a hand-rolled mock:

google-cloud-python/logging/tests/unit/handlers/transports/test_background_thread.py

Lines 420 to 446 in c5acdad

	class _Batch(object):
	def __init__(self):
	self.entries = []
	self.commit_called = False
	self.commit_count = None
	def log_struct(
	self,
	info,
	severity=logging.INFO,
	resource=None,
	labels=None,
	trace=None,
	span_id=None,
	):
	from google.cloud.logging.logger import _GLOBAL_RESOURCE
	assert resource is None
	resource = _GLOBAL_RESOURCE
	self.log_struct_called_with = (info, severity, resource, labels, trace, span_id)
	self.entries.append(info)
	def commit(self):
	self.commit_called = True
	self.commit_count = len(self.entries)
	del self.entries[:]

There will also be test failures due to the use of a mock.Mock passed to _Worker.enqueue:

    def enqueue(
        self, record, message, resource=None, labels=None, trace=None, span_id=None
    ):
        """Queues a log entry to be written by the background thread.
    
        :type record: :class:`logging.LogRecord`
        :param record: Python log record that the handler was called with.
    
        :type message: str
        :param message: The message from the ``LogRecord`` after being
                        formatted by the associated log formatters.
    
        :type resource: :class:`~google.cloud.logging.resource.Resource`
        :param resource: (Optional) Monitored resource of the entry
    
        :type labels: dict
        :param labels: (Optional) Mapping of labels for the entry.
    
        :type trace: str
        :param trace: (optional) traceid to apply to the logging entry.
    
        :type span_id: str
        :param span_id: (optional) span_id within the trace for the log entry.
                        Specify the trace parameter if span_id is set.
        """
        self._queue.put_nowait(
            {
                "info": {"message": message, "python_logger": record.name},
                "severity": record.levelname,
                "resource": resource,
                "labels": labels,
                "trace": trace,
                "span_id": span_id,
>               "timestamp": datetime.datetime.utcfromtimestamp(record.created),
            }
        )
E       TypeError: an integer is required (got type Mock)

[bmccutchon]

If this is going to take a long time to fix, would it make sense to roll back PR #8227 in the meantime?

[tseaver]

• Monitoring and Webrisk fail due to Kokoro-internal error: "Cannot check out non-mergeable pull request as if merged."
• Firestore fails due to Firestore: 'test_watch_collection' systest flakes #7130.
• Spanner fails due to Spanner: 'test_transaction_batch_update_and_execute_dml' systest flakes with unexpected status code. #7504.