Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Inconsistent conversion dates in logs #8689

Closed
btlechowski opened this issue Mar 13, 2020 · 1 comment · Fixed by brave/brave-core#4945
Closed

Inconsistent conversion dates in logs #8689

btlechowski opened this issue Mar 13, 2020 · 1 comment · Fixed by brave/brave-core#4945

Comments

@btlechowski
Copy link

There is a difference between when ad is suppose to convert and when it actually converts

Steps to Reproduce

  1. Watch an ad
  2. Trigger the conversion of the ad
  3. Wait for the conversion

Note: command line used: /usr/bin/brave-browser --enable-logging=stderr --vmodule=brave_ads=3 --brave-ads-staging --rewards=staging=true

Actual result:

[2020-03-13 17:41:29 UTC] Started ad conversion timer for uuid bc47f825-bfbe-40a5-9c64-ec9b12660359 and creative set id 64aa94c2-29b0-4494-8edc-9e60c2e86a7c which will trigger on 2020-03-13 17:47:37.000 UTC
[2020-03-13 17:47:37 UTC] Ad conversion for uuid bc47f825-bfbe-40a5-9c64-ec9b12660359 with creative set id 64aa94c2-29b0-4494-8edc-9e60c2e86a7c triggered on 2020-03-14 13:38:42.000 UTC

Ad conversion for says it triggered on 2020-03-14 13:38:42.000 UTC, but it was actually triggered on 2020-03-13 17:47:37 UTC
The conversion happens usually within 10 minutes after being triggered

Original logs:

[24634:1:0313/184129.745436:INFO:ad_conversion_tracking.cc(178)] Started ad conversion timer for uuid bc47f825-bfbe-40a5-9c64-ec9b12660359 and creative set id 64aa94c2-29b0-4494-8edc-9e60c2e86a7c which will trigger on 2020-03-13 17:47:37.000 UTC
[24634:1:0313/184737.747690:INFO:ad_conversion_tracking.cc(143)] Ad conversion for uuid bc47f825-bfbe-40a5-9c64-ec9b12660359 with creative set id 64aa94c2-29b0-4494-8edc-9e60c2e86a7c triggered on 2020-03-14 13:38:42.000 UTC

Expected result:

Trigger date in log is the same as the actual trigger date

Reproduces how often:

100% repro rate

Brave version (brave://version info)

Verification passed on

Brave 1.5.111 Chromium: 80.0.3987.132 (Official Build) (64-bit)
Revision fcea73228632975e052eb90fcf6cd1752d3b42b4-refs/branch-heads/3987@{#974}
OS Ubuntu 18.04 LTS

cc @brave/legacy_qa @rebron @tmancey @jsecretan

@btlechowski
Copy link
Author

btlechowski commented Mar 17, 2020

Verification passed on

Brave 1.5.112 Chromium: 80.0.3987.132 (Official Build) (64-bit)
Revision fcea73228632975e052eb90fcf6cd1752d3b42b4-refs/branch-heads/3987@{#974}
OS Ubuntu 18.04 LTS

Verified the min date for triggering the conversion is now respected and takes longer than 1 day

[30906:1:0317/172549.793052:INFO:ad_conversion_tracking.cc(178)] Started ad conversion timer for creative_instance_id 36c84fcb-6388-45d8-81ed-5a5d986cd7ef with creative set id de5a82e1-17d6-47e0-a368-17f8f56dfeb3 which will trigger on 2020-03-19 07:10:38.000 UTC
[31755:1:0319/173410.577672:INFO:ad_conversion_tracking.cc(143)] Ad conversion for uuid 36c84fcb-6388-45d8-81ed-5a5d986cd7ef with creative set id de5a82e1-17d6-47e0-a368-17f8f56dfeb3 triggered on 2020-03-19 07:10:38.000 UTC
[31755:1:0319/173410.578178:INFO:ad_conversion_tracking.cc(220)] Saving ad conversions state
[31720:31720:0319/173410.578356:INFO:ads_service_impl.cc(2142)] AdsService Event Log: {"data":{"type":"confirmation","stamp":"2020-03-19T17:34:10Z","notificationId":"36c84fcb-6388-45d8-81ed-5a5d986cd7ef","notificationType":"conversion"}}
[31754:31754:0319/173410.578654:INFO:confirmations_impl.cc(1170)] Confirm action:
  creative_set_id: de5a82e1-17d6-47e0-a368-17f8f56dfeb3
  uuid: 36c84fcb-6388-45d8-81ed-5a5d986cd7ef
  type: conversion

Verified trigger date in ad_conversions.json is the same as in logs

Verified --brave-ads-debug shortens the process.


Verified passed with

Brave 1.5.112 Chromium: 80.0.3987.132 (Official Build) (64-bit)
Revision fcea73228632975e052eb90fcf6cd1752d3b42b4-refs/branch-heads/3987@{#974}
OS macOS Version 10.14.6 (Build 18G3020)
  • Verified the min date for triggering the conversion is now respected and takes longer than 1 day
  • Verified trigger date in ad_conversions.json is the same as in logs
  • Verified --brave-ads-debug shortens the process.

Verification passed on

Brave 1.5.112 Chromium: 80.0.3987.132 (Official Build) (64-bit)
Revision fcea73228632975e052eb90fcf6cd1752d3b42b4-refs/branch-heads/3987@{#974}
OS Windows 10 OS Version 1803 (Build 17134.1006)
  • Verified the min date for triggering the conversion is now respected and takes longer than 1 day
  • Verified trigger date in ad_conversions.json is the same as in logs
  • Verified --brave-ads-debug shortens the process.
[4964:2176:0317/233924.501:INFO:ad_conversion_tracking.cc(143)] Ad conversion for uuid a4ef68c9-5d04-4d0b-b88e-f4f561138dc8 with creative set id c7f96341-726f-4e5d-9494-5686db89664b triggered on 2020-03-17 18:09:24.000 UTC
[4964:2176:0317/233924.501:INFO:ad_conversion_tracking.cc(220)] Saving ad conversions state
[4964:2176:0317/233924.501:INFO:ad_conversion_tracking.cc(64)] Ad conversion queue is empty
[4400:9708:0317/233924.501:INFO:ads_service_impl.cc(2142)] AdsService Event Log: {"data":{"type":"confirmation","stamp":"2020-03-17T23:39:24Z","notificationId":"a4ef68c9-5d04-4d0b-b88e-f4f561138dc8","notificationType":"conversion"}}
[6400:10388:0317/233924.501:INFO:confirmations_impl.cc(1170)] Confirm action:
  creative_set_id: c7f96341-726f-4e5d-9494-5686db89664b
  uuid: a4ef68c9-5d04-4d0b-b88e-f4f561138dc8
  type: conversion

tmancey pushed a commit that referenced this issue Apr 9, 2020
Fixes inconsistent conversion dates in logs - 1.7.x
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants