Page MenuHomePhabricator
Create Task
Maniphest T125423

Database not updated for beta event logging and all-events.log reports 8x for each event [3 pts]
Closed, ResolvedPublic
Actions

Description

Events appear eight times each when running tail -f /srv/log/eventlogging/all-events.log |grep MobileWikiAppArticleSuggestions --line-buffered:

{"clientIp": "684b4027667fea99c8946673178032f760d2a492", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}
{"clientIp": "e78c9d251a0600bd3b3c733a8fbb16117b2e7dc2", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}
{"clientIp": "e699fede4a71d233679563607466bb06994e22df", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}
{"clientIp": "7a93158091a75b39b617a54c05e9c05866abc80a", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}
{"clientIp": "aab88f9b947319786bc9cae0b0d29730e520b481", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}
{"clientIp": "7bf94cba575cd877ba585695b0494bd43f0109b4", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}
{"clientIp": "210501efec4fdad00cc1e339b0d91572bff160ea", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}
{"clientIp": "bf344f8217cc5c100ef85c54d707ead4d2552f2d", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}
{"clientIp": "0d1736256aed5cfcfff2acae686ed8da35383dd4", "event": {"action": "shown", "appInstallID": "ade6b0bb-120f-4733-8fc5-3645a8efbc4f", "pageTitle": "Blue whale", "readMoreList": "Fin_whale|Sei_whale|Humpback_whale", "readMoreSource": 1}, "recvFrom": "deployment-cache-text04.deployment-prep.eqiad.wmflabs", "revision": 12443791, "schema": "MobileWikiAppArticleSuggestions", "seqId": 32899, "timestamp": 1454353193, "userAgent": "\"WikipediaApp/2.1.139-dev-2016-02-01 (Android 6.0.1; Phone) Developer Channel\"", "uuid": "52b17df877255b8dbc74c36f85c1e10b", "wiki": "enwiki"}

The database does not seem to add the events:
echo 'select count(*) from MobileWikiAppArticleSuggestions_15302212;'|ssh deployment-eventlogging03.eqiad.wmflabs mysql -ueventlogging -p68QrOq220717816UycU1 -Dlog:

count(*)
22

Related Objects

Event Timeline

• Niedzielski created this task.Feb 1 2016, 7:23 PM
• Niedzielski raised the priority of this task from to Medium.
• Niedzielski updated the task description. (Show Details)
• Niedzielski added projects: Wikipedia-Android-App-Backlog, Analytics.
• Niedzielski subscribed.
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptFeb 1 2016, 7:23 PM
• Nuria subscribed.Feb 1 2016, 7:29 PM

@Niedzielski: if you need help with this you can always ping us on irc, i can help maybe in a few minutes.

Dbrant moved this task from Needs Triage to Tracking on the Wikipedia-Android-App-Backlog board.Feb 1 2016, 7:33 PM
• Niedzielski added a comment.Feb 1 2016, 7:43 PM

@Nuria, thanks! I just made this phab for tracking. This issue isn't blocking me today but I would like to know if it's a bug on the backend or something that I'm doing wrong. I believe I'm running the commands and interpreting the results correctly.

• Nuria added a comment.Feb 1 2016, 7:44 PM

I am going to reboot instance

• Nuria added a project: Analytics-Kanban.Feb 2 2016, 12:37 AM
• Nuria set Security to None.
• Nuria moved this task from Next Up to In Progress on the Analytics-Kanban board.
• Nuria added a comment.Feb 2 2016, 12:42 AM

Rebooted instance, restarted Eventlogging and restarted mysql

• Nuria added a comment.Feb 2 2016, 4:10 AM

Other tables are inserting events correctly so I think things are back to work:

MariaDB [log]> select max(timestamp) from PageContentSaveComplete_5588433;
+----------------+

max(timestamp)

+----------------+

20160202040940

+----------------+

• Niedzielski added a comment.Feb 2 2016, 4:08 PM

Thanks for restarting the instances! Hm, I think I'm still seeing the same issue on my end :( The row count doesn't update in the database and the log still reports several times for each event.

• Nuria renamed this task from Database not updated for beta event logging and all-events.log reports 8x for each event to Database not updated for beta event logging and all-events.log reports 8x for each event [3].Feb 2 2016, 4:42 PM
• Nuria claimed this task.
Milimetric renamed this task from Database not updated for beta event logging and all-events.log reports 8x for each event [3] to Database not updated for beta event logging and all-events.log reports 8x for each event [3 pts].Feb 2 2016, 5:11 PM
• Nuria added a comment.Feb 2 2016, 11:48 PM

Most definitely something is wrong here as unqiue ids are appearing 9 times in most occasions:

more all-events.log | awk -F"," '{print $15}' | cut -d':' -f2 | sort | uniq -c

2  "fdd267a6cb085128a807bc150ea70ed1"
    9  "fdd3e7987c0259c1869db0e735c8ac44"
    9  "fde4e8a04e9452f8a6b6336a05ec2a39"
    9  "fde808774e5150d1b870a847e1a5a7f1"
    9  "fdefd3e4f96c555f848498b6f74c4c90"
    9  "fdf79a7893965fffbcaf027dee43aa72"
    9  "fdfa773a29905bf789666cf9f9fd13ce"
    9  "fe1c5dbd4d1e5ee78c8eddc4ef69d568"
    9  "fe20d16b88af5d99b36bc4e7e4d462c4"
    9  "fe30fb2fd3a45513aeac6bfc0ee34703"
    9  "fe5141ee73d85e05b458205a56f748ed"
    9  "fe581c6c0e7e511eaed7c89147adbe1e"
    2  "fe6ed477966a5ef5b9598ef4209862b9"
    9  "fec3390d01135a9faf863d2a7f939281"
    9  "fed668b0c91c563fae15b14f0f2d66cf"
    9  "fed6cf5ce5155d87b06536b179ee76af"
    9  "fee182929fb352c096ece259708b0174"
    9  "fef6cbeb0ab55632abbe401f1c09cbca"
    9  "ff0a590fc03358d187b2399575d0cbbf"
    9  "ff30a7b493175281981b0f41a09cdd4c"
    9  "ff430ed1ff4858cd9f0b7e2389580b88"
    9  "ff57ce2da9c750a597533b79acd39ae6"
    2  "ff60de9fd0f357bba9732b8308f95941"
    9  "ff6f05df83bd59829e038be31db08703"
    9  "ff81e9cf080257808ab1f81188fdf8bd"
    9  "ff8a9ac174c455cfbd9d8dc92d6f90f7"
    9  "ffa59f3a00825495b84d0b61582478a7"
    9  "ffddf99ff94b5629b6abaeb6f20bd6e0"
    9  "ffe2fa76ccf4585493e98df27c88fbaf"
• Nuria added a comment.Feb 2 2016, 11:52 PM

Looks like this is not happening on production so it is only an issue on beta labs

• Nuria added a comment.Feb 3 2016, 7:03 PM

I dropped table and now it has 8 new events from today:

MariaDB [log]> select count(*) from MobileWikiAppArticleSuggestions_15302212;
+----------+

count(*)

+----------+

8

+----------+

Still don't know what is going on with logs and events appearing 9 times.

• Nuria added a comment.Feb 3 2016, 7:33 PM

Set up consumer, messages are already duplicated in the topic eventlogging-valid-mixed

• Niedzielski added a comment.Feb 3 2016, 7:46 PM

@Nuria, weird! I just saw the events in the table jump from 8 to 10 but now it's stuck there.

• Nuria added a comment.Feb 3 2016, 7:53 PM
This comment was removed by • Nuria.
• Nuria added a comment.Feb 3 2016, 7:55 PM

@Niedzielski: events are inserted in batches so they will take a while to make it to db

• Niedzielski added a comment.Feb 3 2016, 7:57 PM

@Nuria, ah, I'm used to see them kind of go through in a few seconds. It's been about ten minutes now and the count is still at 10 so maybe it really is stuck?

Milimetric removed a project: Analytics.Feb 4 2016, 6:11 PM
• Nuria moved this task from In Progress to Paused on the Analytics-Kanban board.Feb 12 2016, 4:35 PM
• Nuria added a comment.Feb 12 2016, 7:36 PM

There was a stranded process that was duplicating events into kafka. Fixed now.

• Nuria moved this task from Paused to Done on the Analytics-Kanban board.Feb 12 2016, 7:37 PM
• Niedzielski added a comment.Feb 15 2016, 8:49 PM

Nice, it looks like the duplicate events have been fixed. Unfortunately, now I don't see any events in the log and the database doesn't seem to update.

• Nuria added a comment.Feb 15 2016, 9:01 PM

I rebooted and reinstalled to make sure there was no debug code from our tests. As far as i can see logs are being updated:

root@deployment-eventlogging03:/srv/log/eventlogging# ls -lt
total 9124
-rw-r--r-- 1 eventlogging eventlogging 1055799 Feb 15 21:00 server-side-events.log
-rw-r--r-- 1 eventlogging eventlogging 4665009 Feb 15 21:00 all-events.log
-rw-r--r-- 1 eventlogging eventlogging 3594467 Feb 15 20:59 client-side-events.log
drwxrwxr-x 2 eventlogging eventlogging 12288 Feb 15 06:40 archive

I see other events on the all-events log so please make sure to check your events are valid.

• Niedzielski added a comment.Feb 15 2016, 9:11 PM

@Nuria, my mistake! I was using the wrong app build flavor. Thank you for fixing this issue!

• Nuria closed this task as Resolved.Feb 15 2016, 9:12 PM
Dbrant moved this task from Tracking to Resolved/Invalid/Declined/Legacy on the Wikipedia-Android-App-Backlog board.Feb 29 2016, 3:45 PM
• Niedzielski mentioned this in T159845: Android development event logging broken.Mar 7 2017, 4:34 PM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL