#8389 Missing fedmsgs in datagrepper/resultsdb from jenkins-continuous-infra.apps.ci.centos.org
Closed: Fixed by kevin. Opened by bstinson.

We've been debugging this all morning (US-timezone). We found

  • messages seem to be properly sent from the jenkins instance
  • messages are arriving at the ingress of the fedmsg relay
  • messages are exiting the egress of the fedmsg relay
  • messages are signed properly

But, we don't see messages showing up in datagrepper or resultsdb in Fedora Infrastructure. Our current suspect is something in whatever process is bridging fedmsg -> fedora messaging, but we're not sure where to start probing this.

Here's a log of troubleshooting so far: https://pagure.io/fedora-ci/general/issue/82

cc: @jimbair @astepano @bgoncalv @bookwar @pingou


This is a pretty critical issue as CI test results stopped being visible for developers.

The one of possible ways for us to investigate it further is to revert Jenkins to the previous state (before the JMS plugin update)

But this is not a good way because:
1) there is no confidence in that it actually solves anything
2) it will delay the switch to Fedora Messaging for at least two more weeks.

That's why we need Fedora Infra input on it.

So I've been looking a little bit into this.

I've ran the command: fedmsg-tail --really-pretty --no-validate --query topic |grep centos on my laptop, batcave01 and the two datagrepper hosts.
CI messages appeared fine on all four hosts.

I then run the command: fedmsg-tail --really-pretty --query topic |grep centos in parallel on a second terminal in my laptop, on a second terminal on batcave and in one of the two datagrepper.
The goal there was to determine if --no-validate made a difference or not. This would have been a way to check if there was a certificate/signature issue.
The messages appeared with on all the consumer, with or without --no-validate.

I then realized the messages are uploaded in the database on busgateway01. So I went there and check the logs of fedmsg-hub: journalctl -lfu fedmsg-hub -n 100.
This led me to find a traceback when receiving messages from the CI pipeline:

ProgrammingError: (ProgrammingError) column "timestamp" is of type timestamp without time zone but expression is of type bigint
LINE 1: ...allpackages-pr.package.test.functional.complete', 1574091970...

Looking in the error, it seem it is finding a timestamp with the value 1574091970506.

A little python code:

>>> import datetime
>>> datetime.datetime.fromtimestamp(1574091970506)
Traceback (most recent call last):
  File "<input>", line 1, in <module>
    datetime.datetime.fromtimestamp(1574091970506)
ValueError: year 51850 is out of range

So I'm currently strongly suspecting that this is our issue :)

Going down the rabbit hole a little, it seems that the last 3 digits are the unwanted ones:

>>> datetime.datetime.fromtimestamp(1574091970506)
Traceback (most recent call last):
  File "<input>", line 1, in <module>
    datetime.datetime.fromtimestamp(1574091970506)
ValueError: year 51850 is out of range
>>> datetime.datetime.fromtimestamp(157409197050)
datetime.datetime(6958, 2, 5, 17, 57, 30)
>>> datetime.datetime.fromtimestamp(15740919705)
datetime.datetime(2468, 10, 22, 15, 41, 45)
>>> datetime.datetime.fromtimestamp(1574091970)
datetime.datetime(2019, 11, 18, 16, 46, 10)
>>> datetime.datetime.fromtimestamp(157409197)
datetime.datetime(1974, 12, 27, 21, 46, 37)

(Cf the one before last)

The older version of JMS plugin was not setting the timestamp, so we were sending with '0'. Since version 1.1.8 the plugin set timestamp and uses it in milliseconds.

https://wiki.jenkins.io/display/JENKINS/JMS+Messaging+Plugin

https://github.com/jenkinsci/jms-messaging-plugin/pull/131/files

the plugin set timestamp and uses it in milliseconds.

This is most likely the issue then. We're expecting that the timestamp is an UNIX timestamp: https://en.wikipedia.org/wiki/Unix_time which is in second.

So,, I think this is fixed now? Is there anything further to do here?

Yes, this is fixed and we can close it out. Thank you! Fix for those curious in case it wasn't listed above: https://github.com/bstinsonmhk/jms-messaging-plugin/tree/fix-fedmsg-timestamp

Metadata Update from @kevin:
- Issue close_status updated to: Fixed
- Issue status updated to: Closed (was: Open)

Metadata