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.

Sign up for GitHub

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

Jump to bottom

[ads] Brave News Inline orphaned ad events are not purged #38373

Closed
btlechowski opened this issue May 16, 2024 · 6 comments · Fixed by brave/brave-core#23720
Closed

[ads] Brave News Inline orphaned ad events are not purged #38373

btlechowski opened this issue May 16, 2024 · 6 comments · Fixed by brave/brave-core#23720
Assignees
@tmancey
Labels
feature/ads OS/Android Fixes related to Android browser functionality OS/Desktop priority/P1 A very extremely bad problem. We might push a hotfix for it. QA Pass - Android ARM QA Pass - Android Tab QA Pass-Linux QA Pass-macOS QA Pass-Win64 QA/Test-All-Platforms QA/Yes regression release-notes/exclude
Projects
Ads
Milestone
1.66.x - Release #2

Comments

@btlechowski
Copy link

Steps to Reproduce

  1. Clean profile
  2. Run Brave with
--enable-logging=stderr --vmodule="*/variations/*"=6,"*/bat-native-ledger/*"=6,"*/brave_rewards/*"=6,"*/bat-native-ads/*"=6,"*bat-native-confirmations/*"=6,"*/brave_ads/*"=9,"*/brave_user_model/*"=6,"*/bat_ads/*"=6,"*/whats_new/*"=9 --variations-server-url=https://variations.bravesoftware.com/seed1 --rewards=staging=true,debug=true --use-dev-goupdater-url --enable-features=ShouldAlwaysRunBraveAdsService,ShouldAlwaysTriggerBraveSearchResultAdEvents,ShouldLaunchBraveAdsAsInProcessService,ShouldSupportSearchResultAds,ShouldAlwaysTriggerBraveNewTabPageAdEvents,CustomNotificationAds,NotificationAds:default_ads_per_hour/5,InlineContentAds:maximum_ads_per_day/1
  1. Open NTP
  2. Enable Brave News
  3. Serve a Brave News inline ad, but do not view it
  4. Close the tab
  5. Open NTP
  6. View a Brave News inline ad

Actual result:

orphaned ad events are not purged

Ad is not shown:

[14964:14964:1112/061440.742187:VERBOSE2:permission_rule_util.cc(16)] You have exceeded the allowed inline content ads per day
[14964:14964:1112/061440.747845:VERBOSE1:inline_content_ad_serving.cc(48)] Inline content ad not served: Not allowed due to permission rules

Expected result:

orphaned ad events are purged
Ad is shown

Reproduces how often:

Easily reproduced

Brave version (brave://version info)

Brave 1.66.110 Chromium: 125.0.6422.60 (Official Build) (64-bit)
Revision de593d76e2ca4d02faa85bf1ca27bcf3ee46793c
OS Linux

cc @tmancey @aseren
@tmancey tmancey added this to In progress in Ads May 16, 2024
@tmancey tmancey self-assigned this May 16, 2024
@btlechowski btlechowski mentioned this issue May 16, 2024
Closed
@tmancey tmancey added the priority/P3 The next thing for us to work on. It'll ride the trains. label May 16, 2024
@tmancey tmancey moved this from In progress to Review in Ads May 16, 2024
@tmancey tmancey added priority/P2 A bad problem. We might uplift this to the next planned release. and removed priority/P3 The next thing for us to work on. It'll ride the trains. labels May 16, 2024
@tmancey tmancey changed the title Brave News Inline orphaned ad events are not purged [ads] Brave News Inline orphaned ad events are not purged May 16, 2024
@tmancey tmancey mentioned this issue May 17, 2024
Merged
24 tasks
Ads automation moved this from Review to Done May 17, 2024
@brave-builds brave-builds added this to the 1.68.x - Nightly milestone May 17, 2024
This was referenced May 17, 2024
Merged
Merged
@tmancey tmancey added priority/P1 A very extremely bad problem. We might push a hotfix for it. OS/Android Fixes related to Android browser functionality and removed priority/P2 A bad problem. We might uplift this to the next planned release. labels May 17, 2024
This was referenced May 20, 2024
Closed
Open
@kjozwiak
Copy link
Member

The above requires 1.66.113 or higher for 1.66.x verification 👍 @btlechowski you can probably just run through a few spot checks on all the platforms as both brave/brave-core#23720 (comment) & brave/brave-core#23720 (comment) were pretty thorough checks.

@btlechowski
Copy link
Author

Verified with

Brave 1.66.113 Chromium: 125.0.6422.76 (Official Build) (64-bit)
Revision b1864a9a0152d4f1631121c6b13a7426f50cf336
OS Windows 10 Version 22H2 (Build 19045.4412)

Test plan from #38373 (comment)

Verified orphaned events were purged

[3388:1980:0522/151236.437:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 399248477
[3388:1980:0522/151236.536:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for beaceed4-5e98-49ff-a223-3ae8a24857f2 placement ids

Verified ad was served again

[3388:1980:0522/151349.323:VERBOSE1:eligible_inline_content_ads_v2.cc(39)] Get eligible inline content ads
[3388:1980:0522/151349.327:VERBOSE3:priority_util.h(21)] 1 untargeted ads with a priority of 51 in bucket 1
[3388:1980:0522/151349.327:VERBOSE1:eligible_inline_content_ads_v2.cc(132)] Predicted ad with creative instance id fe7e925e-5490-431b-b788-4c64f5543e0d and a priority of 51
[3388:1980:0522/151349.327:VERBOSE1:inline_content_ad_serving.cc(114)] Found 1 eligible ads
[3388:1980:0522/151349.327:VERBOSE1:inline_content_ad_serving.cc(120)] Chosen eligible ad with creative instance id fe7e925e-5490-431b-b788-4c64f5543e0d and a priority of 51
[3388:1980:0522/151349.327:VERBOSE1:inline_content_ad_handler.cc(125)] Cached inline content ad with placement id 9664386e-1032-4b61-b91e-cfd2acb76543 and tab id 399248479
[3388:1980:0522/151349.327:VERBOSE1:inline_content_ad_handler.cc(186)] Served inline content ad:
  placementId: 9664386e-1032-4b61-b91e-cfd2acb76543
  creativeInstanceId: fe7e925e-5490-431b-b788-4c64f5543e0d
  creativeSetId: f1886272-e83d-4efb-b53c-72a1c79ae0b3
  campaignId: 07de7f05-ab32-4af0-a350-a1bce4427eac
  advertiserId: 93130af3-2def-4ecb-b836-b3772e73b3c9
  segment: untargeted
  title: Staging - Inline Test 3
  description: Fung Brave News Inline Display Ad - windows
  imageUrl: https://pcdn.brave.com/brave-ads/468beb93-2458-5d3e-8d7b-bc1f387d2e9b.webp.pad
  dimensions: 900x750
  ctaText: Work at Brave
  targetUrl: https://brave.com/careers

Test plan from brave/brave-core#23720

Confirm Tab id # did change appears in the log when navigating to a new URL

[3388:1980:0522/151535.439:VERBOSE2:tab_manager.cc(253)] Tab id 399248481 did change

Confirm Created tab with id # and Tab id # did become focused appear in the log when opening a new tab

[3388:1980:0522/151638.343:VERBOSE2:tab_manager.cc(248)] Created tab with id 399248482
[3388:1980:0522/151638.344:VERBOSE2:tab_manager.cc(259)] Tab id 399248482 did become focused

Confirm Restored focused tab with id # appear in the log when restoring a tab, i.e., after relaunching the browser

[6516:4488:0522/151727.339:VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 399248550
[6516:4488:0522/151727.339:VERBOSE2:tab_manager.cc(243)] Restored occluded tab with id 399248549

Confirm Tab id # did become focused appears in the log when focusing on an existing tab

[6516:4488:0522/151843.787:VERBOSE2:tab_manager.cc(259)] Tab id 399248550 did become occluded
[6516:4488:0522/151843.787:VERBOSE2:tab_manager.cc(259)] Tab id 399248551 did become focused

Confirm Tab id # did become occluded appears in the log when a tab becomes inactive.

[6516:4488:0522/151843.787:VERBOSE2:tab_manager.cc(259)] Tab id 399248550 did become occluded
[6516:4488:0522/151843.787:VERBOSE2:tab_manager.cc(259)] Tab id 399248551 did become focused

Confirm Tab id # did become occluded and Tab id # was closed appear in the log when closing a tab

[6516:4488:0522/151948.155:VERBOSE2:tab_manager.cc(259)] Tab id 399248551 did become occluded
[6516:4488:0522/151948.172:VERBOSE2:tab_manager.cc(259)] Tab id 399248550 did become focused
[6516:4488:0522/151948.173:VERBOSE2:tab_manager.cc(265)] Tab id 399248551 was closed

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the last tab

[6516:4488:0522/152032.622:VERBOSE2:tab_manager.cc(259)] Tab id 399248549 did become occluded
[6516:4488:0522/152032.719:VERBOSE2:tab_manager.cc(265)] Tab id 399248549 was closed
[6516:4488:0522/152032.719:VERBOSE2:tab_manager.cc(95)] There are no tabs

Confirm Created tab with id # and Tab id # did become focused appear in the log when launching the browser after closing the last tab

[11440:11044:0522/152121.866:VERBOSE2:tab_manager.cc(248)] Created tab with id 399248617
[11440:11044:0522/152121.866:VERBOSE2:tab_manager.cc(259)] Tab id 399248617 did become focused
[11440:11044:0522/152121.867:VERBOSE2:tab_manager.cc(167)] Tab id 399248617 HTML content changed

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the browser window

[8120:532:0522/152505.308:VERBOSE2:tab_manager.cc(259)] Tab id 399248755 did become occluded
[8120:532:0522/152505.318:VERBOSE2:tab_manager.cc(259)] Tab id 399248754 did become focused
[8120:532:0522/152516.477:VERBOSE2:tab_manager.cc(259)] Tab id 399248754 did become occluded
[8120:532:0522/152516.545:VERBOSE2:tab_manager.cc(265)] Tab id 399248755 was closed
[8120:532:0522/152516.546:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 399248755
[8120:532:0522/152516.546:VERBOSE1:inline_content_ad_handler.cc(138)] There are no orphaned inline content ad placements for tab id 399248755
[8120:532:0522/152516.546:VERBOSE2:tab_manager.cc(265)] Tab id 399248754 was closed
[8120:532:0522/152516.546:VERBOSE2:tab_manager.cc(95)] There are no tabs

Confirm Restored focused tab with id # appear in the log when launching the browser after closing the browser window

[6484:10924:0522/152733.908:VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 399248827

Confirm Purging orphaned inline content ad placements for tab id # and Purged orphaned inline content ad events for ... placement ids appear in the log when closing at tab with a served inline content ad

[4440:10684:0522/152930.995:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 335601112
[4440:10684:0522/152931.038:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 0a4cb3d4-968d-40d3-94f9-c278c570ced2 placement ids

Confirm Purging orphaned inline content ad placements for tab id # and There are no orphaned inline content ad placements for tab id # do not appear in the log when closing a tab with a viewed inline content ad

Log states events are purged:

[4440:10684:0522/152930.995:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 335601112
[4440:10684:0522/152931.038:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 0a4cb3d4-968d-40d3-94f9-c278c570ced2 placement ids

Logged #38425

Confirm orphaned inline content ads are purged when launching the browser

[8056:656:0522/153311.540:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 335601177

Confirm Browser did enter foreground appears in the log when the browser is foregrounded

[1868:11712:0522/153415.622:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did enter background appears in the log when the browser is backgrounded

[1868:11712:0522/153407.012:VERBOSE1:browser_manager.cc(76)] Browser did enter background

Confirm Browser did become active appears in the log when the browser becomes active

[1868:11712:0522/153415.625:VERBOSE1:browser_manager.cc(53)] Browser did become active

Confirm Browser did resign active appears in the log when the browser resigns active

[1868:11712:0522/153417.384:VERBOSE1:browser_manager.cc(53)] Browser did resign active

Confirm Browser did enter foreground, Browser did become active, Created tab with id # and Tab id # did become focused appear in the log when the browser is launched

[884:10948:0522/153617.042:VERBOSE1:browser_manager.cc(53)] Browser did become active
[884:10948:0522/153617.043:VERBOSE2:tab_manager.cc(248)] Created tab with id 1817181331
[884:10948:0522/153617.044:VERBOSE2:tab_manager.cc(259)] Tab id 1817181331 did become focused
[884:10948:0522/153617.045:VERBOSE2:tab_manager.cc(167)] Tab id 1817181331 HTML content changed
[884:10948:0522/153617.045:VERBOSE1:conversions.cc(57)] Checking for conversions
[884:10948:0522/153617.045:VERBOSE1:text_embedding_processor.cc(101)] chrome scheme is not supported for processing HTML content
[884:10948:0522/153617.045:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did become active and Tab id # did become focused appear in the log when the browser is restored from being minimized

[884:10948:0522/153819.745:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground
[884:10948:0522/153819.748:VERBOSE1:browser_manager.cc(53)] Browser did become active
[884:10948:0522/153819.752:VERBOSE2:tab_manager.cc(259)] Tab id 1817181331 did become focused

Confirm Browser did resign active and Tab id # did become occluded appear in the log when the browser is minimized


[884:10948:0522/153751.105:VERBOSE2:tab_manager.cc(259)] Tab id 1817181331 did become occluded
[884:10948:0522/153751.110:VERBOSE1:browser_manager.cc(53)] Browser did resign active
[884:10948:0522/153751.111:VERBOSE1:browser_manager.cc(76)] Browser did enter background

Sanity test with multiple browser windows

Logged #38427

media playing

``` [884:10948:0522/153946.138:VERBOSE2:permission_rules.cc(263)] Media is playing [884:10948:0522/153946.139:VERBOSE1:notification_ad_serving.cc(77)] Notification ad not served: Not allowed due to permission rules 

</details>

@btlechowski
Copy link
Author

Verified with

Brave 1.66.113 Chromium: 125.0.6422.76 (Official Build) (64-bit)
Revision b1864a9a0152d4f1631121c6b13a7426f50cf336
OS Linux

Test plan from #38373 (comment)

Verified orphaned events were purged

[7052:7052:0522/154421.231331:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 612467067
[7052:7052:0522/154421.248504:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for ad5060d3-1966-4582-8844-e32f0e5298c7 placement ids

Verified ad was served again

[7052:7052:0522/154503.932396:VERBOSE1:inline_content_ad_handler.cc(164)] Opportunity arose to serve an inline content ad
[7052:7052:0522/154503.933877:VERBOSE1:text_classification_model.cc(78)] No text classification probabilities found for en_US.UTF-8 locale
[7052:7052:0522/154503.934904:VERBOSE1:eligible_inline_content_ads_v2.cc(39)] Get eligible inline content ads
[7052:7052:0522/154503.940860:VERBOSE3:priority_util.h(21)] 2 untargeted ads with a priority of 51 in bucket 1
[7052:7052:0522/154503.941387:VERBOSE1:eligible_inline_content_ads_v2.cc(132)] Predicted ad with creative instance id e4958d00-e35c-4134-a408-1fbcf274d5ae and a priority of 51
[7052:7052:0522/154503.941628:VERBOSE1:inline_content_ad_serving.cc(114)] Found 1 eligible ads
[7052:7052:0522/154503.941853:VERBOSE1:inline_content_ad_serving.cc(120)] Chosen eligible ad with creative instance id e4958d00-e35c-4134-a408-1fbcf274d5ae and a priority of 51
[7052:7052:0522/154503.942079:VERBOSE1:inline_content_ad_handler.cc(125)] Cached inline content ad with placement id 383ebb07-d092-4e1e-b380-8503e70e6992 and tab id 612467069
[7052:7052:0522/154503.942302:VERBOSE1:inline_content_ad_handler.cc(186)] Served inline content ad:
  placementId: 383ebb07-d092-4e1e-b380-8503e70e6992
  creativeInstanceId: e4958d00-e35c-4134-a408-1fbcf274d5ae
  creativeSetId: 8b848823-c47f-43de-a753-2efa8dea6863
  campaignId: 07de7f05-ab32-4af0-a350-a1bce4427eac
  advertiserId: 93130af3-2def-4ecb-b836-b3772e73b3c9
  segment: untargeted
  title: Staging - Inline Test 1
  description: Fung Brave News Inline Display Ad - mac/linux
  imageUrl: https://pcdn.brave.com/brave-ads/468beb93-2458-5d3e-8d7b-bc1f387d2e9b.webp.pad
  dimensions: 900x750
  ctaText: Work at Brave
  targetUrl: https://brave.com/careers
[7052:7052:0522/154503.999495:VERBOSE3:inline_content_ad_handler.cc(193)] Served inline content ad impression with placement id 383ebb07-d092-4e1e-b380-8503e70e6992 and creative instance id e4958d00-e35c-4134-a408-1fbcf274d5ae

Test plan from brave/brave-core#23720

Confirm Tab id # did change appears in the log when navigating to a new URL

[7052:7052:0522/154603.716934:VERBOSE2:tab_manager.cc(253)] Tab id 612467069 did change

Confirm Created tab with id # and Tab id # did become focused appear in the log when opening a new tab

[7052:7052:0522/154735.364226:VERBOSE2:tab_manager.cc(248)] Created tab with id 612467071
[7052:7052:0522/154735.368612:VERBOSE2:tab_manager.cc(259)] Tab id 612467071 did become focused

Confirm Restored focused tab with id # appear in the log when restoring a tab, i.e., after relaunching the browser

[7459:7459:0522/154810.654646:VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 612467140
[7459:7459:0522/154812.168552:VERBOSE2:tab_manager.cc(243)] Restored occluded tab with id 612467142
[7459:7459:0522/154813.749421:VERBOSE2:tab_manager.cc(243)] Restored occluded tab with id 612467141

Confirm Tab id # did become focused appears in the log when focusing on an existing tab

[7459:7459:0522/154943.183630:VERBOSE2:tab_manager.cc(259)] Tab id 612467140 did become occluded
[7459:7459:0522/154943.201498:VERBOSE2:tab_manager.cc(259)] Tab id 612467139 did become focused

Confirm Tab id # did become occluded appears in the log when a tab becomes inactive.

[7459:7459:0522/154943.183630:VERBOSE2:tab_manager.cc(259)] Tab id 612467140 did become occluded
[7459:7459:0522/154943.201498:VERBOSE2:tab_manager.cc(259)] Tab id 612467139 did become focused

Confirm Tab id # did become occluded and Tab id # was closed appear in the log when closing a tab

[7459:7459:0522/155038.015427:VERBOSE2:tab_manager.cc(259)] Tab id 612467140 did become occluded
[7459:7459:0522/155038.025448:VERBOSE2:tab_manager.cc(259)] Tab id 612467141 did become focused
[7459:7459:0522/155038.029045:VERBOSE2:tab_manager.cc(265)] Tab id 612467140 was closed

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the last tab

[7459:7459:0522/155105.355308:VERBOSE2:tab_manager.cc(259)] Tab id 612467139 did become occluded
[7459:7459:0522/155105.388345:VERBOSE2:tab_manager.cc(265)] Tab id 612467139 was closed
[7459:7459:0522/155105.390397:VERBOSE2:tab_manager.cc(95)] There are no tabs

Confirm Created tab with id # and Tab id # did become focused appear in the log when launching the browser after closing the last tab

[7672:7672:0522/155138.348787:VERBOSE2:tab_manager.cc(248)] Created tab with id 612467212
[7672:7672:0522/155138.354534:VERBOSE2:tab_manager.cc(259)] Tab id 612467212 did become focused
[7672:7672:0522/155138.355844:VERBOSE2:tab_manager.cc(167)] Tab id 612467212 HTML content changed

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the browser window

[8204:8204:0522/155425.193625:VERBOSE2:tab_manager.cc(259)] Tab id 612467415 did become occluded
[8204:8204:0522/155425.231645:VERBOSE2:tab_manager.cc(265)] Tab id 612467415 was closed
[8204:8204:0522/155425.239936:VERBOSE2:tab_manager.cc(95)] There are no tabs
[8204:8204:0522/155425.241983:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 612467415

Confirm Restored focused tab with id # appear in the log when launching the browser after closing the browser window

[8381:8381:0522/155512.770409:VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 612467489

Confirm Purging orphaned inline content ad placements for tab id # and Purged orphaned inline content ad events for ... placement ids appear in the log when closing at tab with a served inline content ad

[8381:8381:0522/155614.834179:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 612467489
[8381:8381:0522/155614.849832:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 1e561583-38fa-4522-bb44-4176b0bc4ec1 placement ids

Confirm Purging orphaned inline content ad placements for tab id # and There are no orphaned inline content ad placements for tab id # do not appear in the log when closing a tab with a viewed inline content ad

Log states events are purged:

[8381:8381:0522/155701.984219:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 612467504
[8381:8381:0522/155701.990787:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 8a3749b6-c60a-423a-b62a-f00068458448 placement ids

Logged #38425

Confirm orphaned inline content ads are purged when launching the browser

[8554:8554:0522/155842.289276:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 1642460483

Confirm Browser did enter foreground appears in the log when the browser is foregrounded

[8855:8855:0522/155928.819214:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did enter background appears in the log when the browser is backgrounded

[8855:8855:0522/155930.593909:VERBOSE1:browser_manager.cc(76)] Browser did enter background

Confirm Browser did become active appears in the log when the browser becomes active

[8855:8855:0522/155928.815287:VERBOSE1:browser_manager.cc(53)] Browser did become active

Confirm Browser did resign active appears in the log when the browser resigns active

[8855:8855:0522/155930.591650:VERBOSE1:browser_manager.cc(53)] Browser did resign active

Confirm Browser did enter foreground, Browser did become active, Created tab with id # and Tab id # did become focused appear in the log when the browser is launched

[9081:9081:0522/160145.496798:VERBOSE1:resource_component_registrar.cc(52)] Registering Brave Ads Resources (US) with id iblokdlgekdjophgeonmanpnjihcjkjj
[9081:9081:0522/160145.499482:VERBOSE1:browser_manager.cc(53)] Browser did become active
[9081:9081:0522/160145.526804:VERBOSE2:tab_manager.cc(248)] Created tab with id 1578151456
[9081:9081:0522/160145.536984:VERBOSE2:tab_manager.cc(259)] Tab id 1578151456 did become focused
[9081:9081:0522/160145.550954:VERBOSE2:tab_manager.cc(167)] Tab id 1578151456 HTML content changed
[9081:9081:0522/160145.561355:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did become active and Tab id # did become focused appear in the log when the browser is restored from being minimized

[9081:9081:0522/160258.259819:VERBOSE1:browser_manager.cc(53)] Browser did become active
[9081:9081:0522/160258.262347:VERBOSE2:tab_manager.cc(259)] Tab id 1578151456 did become focused
[9081:9081:0522/160258.268429:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did resign active and Tab id # did become occluded appear in the log when the browser is minimized


[9081:9081:0522/160302.200408:VERBOSE1:browser_manager.cc(53)] Browser did resign active
[9081:9081:0522/160302.207851:VERBOSE2:tab_manager.cc(259)] Tab id 1578151456 did become occluded
[9081:9081:0522/160302.209473:VERBOSE1:browser_manager.cc(76)] Browser did enter background

Sanity test with multiple browser windows

Logged #38427

media playing

``` [9081:9081:0522/160509.272239:VERBOSE2:permission_rules.cc(263)] Media is playing [9081:9081:0522/160509.272907:VERBOSE1:notification_ad_serving.cc(77)] Notification ad not served: Not allowed due to permission rules 

</details>

@btlechowski
Copy link
Author

Verified with

Brave 1.66.113 Chromium: 125.0.6422.76 (Official Build) (arm64)
Revision b1864a9a0152d4f1631121c6b13a7426f50cf336
OS macOS Version 14.4 (Build 23E214)

Test plan from #38373 (comment)

Verified orphaned events were purged

[931:259:0522/170949.630302:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 946650486
[931:259:0522/170949.633035:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for e74a5d38-b4a7-45fc-be8a-803137a92dd9 placement ids

Verified ad was served again

[931:259:0522/171038.161463:VERBOSE1:text_classification_model.cc(78)] No text classification probabilities found for en_PL locale
[931:259:0522/171038.161474:VERBOSE1:eligible_inline_content_ads_v2.cc(39)] Get eligible inline content ads
[931:259:0522/171038.162265:VERBOSE3:priority_util.h(21)] 2 untargeted ads with a priority of 51 in bucket 1
[931:259:0522/171038.162285:VERBOSE1:eligible_inline_content_ads_v2.cc(132)] Predicted ad with creative instance id 211a9ff9-48bf-4b79-bd2a-f6b450edac0a and a priority of 51
[931:259:0522/171038.162294:VERBOSE1:inline_content_ad_serving.cc(114)] Found 1 eligible ads
[931:259:0522/171038.162300:VERBOSE1:inline_content_ad_serving.cc(120)] Chosen eligible ad with creative instance id 211a9ff9-48bf-4b79-bd2a-f6b450edac0a and a priority of 51
[931:259:0522/171038.162306:VERBOSE1:inline_content_ad_handler.cc(125)] Cached inline content ad with placement id ba078aa3-ba0d-4474-9252-35df4ae4242b and tab id 946650488
[931:259:0522/171038.162312:VERBOSE1:inline_content_ad_handler.cc(186)] Served inline content ad:
  placementId: ba078aa3-ba0d-4474-9252-35df4ae4242b
  creativeInstanceId: 211a9ff9-48bf-4b79-bd2a-f6b450edac0a
  creativeSetId: 8b848823-c47f-43de-a753-2efa8dea6863
  campaignId: 07de7f05-ab32-4af0-a350-a1bce4427eac
  advertiserId: 93130af3-2def-4ecb-b836-b3772e73b3c9
  segment: untargeted
  title: [Staging] Aspect Ratio
  description: Test Aspect Ratio
  imageUrl: https://pcdn.bravesoftware.com/brave-news-ads/0f61aa5e-d79f-4585-9835-b75afb3343b0.jpg.pad
  dimensions: 900x750
  ctaText: Aspect Ratio
  targetUrl: https://brave.com/careers/
[931:259:0522/171038.163830:VERBOSE3:inline_content_ad_handler.cc(193)] Served inline content ad impression with placement id ba078aa3-ba0d-4474-9252-35df4ae4242b and creative instance id 211a9ff9-48bf-4b79-bd2a-f6b450edac0a

Test plan from brave/brave-core#23720

Confirm Tab id # did change appears in the log when navigating to a new URL

[931:259:0522/171406.875144:VERBOSE2:tab_manager.cc(253)] Tab id 946650488 did change

Confirm Created tab with id # and Tab id # did become focused appear in the log when opening a new tab

[931:259:0522/171655.926256:VERBOSE2:tab_manager.cc(259)] Tab id 946650488 did become occluded
[931:259:0522/171655.949024:VERBOSE2:tab_manager.cc(248)] Created tab with id 946650489
[931:259:0522/171655.949485:VERBOSE2:tab_manager.cc(259)] Tab id 946650489 did become focused

Confirm Restored focused tab with id # appear in the log when restoring a tab, i.e., after relaunching the browser

[1049:259:0522/171816.027390:VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 946650554
[1049:259:0522/171816.045691:VERBOSE2:tab_manager.cc(243)] Restored occluded tab with id 946650552
[1049:259:0522/171816.078368:VERBOSE2:tab_manager.cc(243)] Restored occluded tab with id 946650553

Confirm Tab id # did become focused appears in the log when focusing on an existing tab

[1049:259:0522/172134.603236:VERBOSE2:tab_manager.cc(259)] Tab id 946650554 did become occluded
[1049:259:0522/172134.609392:VERBOSE2:tab_manager.cc(259)] Tab id 946650553 did become focused
[1049:259:0522/172135.595760:VERBOSE2:tab_manager.cc(259)] Tab id 946650553 did become occluded
[1049:259:0522/172135.601971:VERBOSE2:tab_manager.cc(259)] Tab id 946650554 did become focused

Confirm Tab id # did become occluded appears in the log when a tab becomes inactive.

[1049:259:0522/172134.603236:VERBOSE2:tab_manager.cc(259)] Tab id 946650554 did become occluded
[1049:259:0522/172134.609392:VERBOSE2:tab_manager.cc(259)] Tab id 946650553 did become focused
[1049:259:0522/172135.595760:VERBOSE2:tab_manager.cc(259)] Tab id 946650553 did become occluded
[1049:259:0522/172135.601971:VERBOSE2:tab_manager.cc(259)] Tab id 946650554 did become focused

Confirm Tab id # did become occluded and Tab id # was closed appear in the log when closing a tab

[1049:259:0522/172239.901175:VERBOSE2:tab_manager.cc(259)] Tab id 946650554 did become occluded
[1049:259:0522/172239.902951:VERBOSE2:tab_manager.cc(259)] Tab id 946650553 did become focused
[1049:259:0522/172239.903268:VERBOSE2:tab_manager.cc(265)] Tab id 946650554 was closed

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the last tab

[1049:259:0522/172313.765406:VERBOSE2:tab_manager.cc(259)] Tab id 946650553 did become focused
[1049:259:0522/172315.906189:VERBOSE2:tab_manager.cc(259)] Tab id 946650553 did become occluded
[1049:259:0522/172315.911359:VERBOSE2:tab_manager.cc(259)] Tab id 946650552 did become focused
[1049:259:0522/172315.912940:VERBOSE2:tab_manager.cc(265)] Tab id 946650553 was closed
[1049:259:0522/172315.913334:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 946650553
[1049:259:0522/172315.913370:VERBOSE1:inline_content_ad_handler.cc(138)] There are no orphaned inline content ad placements for tab id 946650553
[1049:259:0522/172317.235275:VERBOSE2:tab_manager.cc(259)] Tab id 946650552 did become occluded
[1049:259:0522/172317.263203:VERBOSE2:tab_manager.cc(265)] Tab id 946650552 was closed
[1049:259:0522/172317.263310:VERBOSE2:tab_manager.cc(95)] There are no tabs

Confirm Created tab with id # and Tab id # did become focused appear in the log when launching the browser after closing the last tab

[1049:259:0522/172404.904615:VERBOSE2:tab_manager.cc(248)] Created tab with id 946650563
[1049:259:0522/172404.905283:VERBOSE2:tab_manager.cc(259)] Tab id 946650563 did become focused

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the browser window

[1049:259:0522/172514.957737:VERBOSE2:tab_manager.cc(259)] Tab id 946650563 did become occluded
[1049:259:0522/172514.979207:VERBOSE2:tab_manager.cc(265)] Tab id 946650563 was closed
[1049:259:0522/172514.979332:VERBOSE2:tab_manager.cc(95)] There are no tabs

Confirm Restored focused tab with id # appear in the log when launching the browser after closing the browser window

On macOS closing last window does not close browser, but closes the tabs permanently, so on restoration new tab is shown.

[1049:259:0522/172737.252897:VERBOSE2:tab_manager.cc(248)] Created tab with id 946650575
[1049:259:0522/172737.253199:VERBOSE2:tab_manager.cc(259)] Tab id 946650575 did become focused

Confirm Purging orphaned inline content ad placements for tab id # and Purged orphaned inline content ad events for ... placement ids appear in the log when closing at tab with a served inline content ad

[1049:259:0522/173027.575567:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 946650575
[1049:259:0522/173027.578579:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 8bd4eec7-a941-4e9f-a43c-00fb84fa1d6f placement ids

Confirm Purging orphaned inline content ad placements for tab id # and There are no orphaned inline content ad placements for tab id # do not appear in the log when closing a tab with a viewed inline content ad

Log states events are purged:

[1049:259:0522/173312.497973:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 946650576
[1049:259:0522/173312.498412:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 3a101b2b-7d0a-4b62-9645-aef19ea67110 placement ids

Logged #38425

Confirm orphaned inline content ads are purged when launching the browser

[1103:259:0522/173510.064934:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 1609648376
[1103:259:0522/173510.064960:VERBOSE2:tab_manager.cc(265)] Tab id 1609648375 was closed
[1103:259:0522/173510.064970:VERBOSE2:tab_manager.cc(95)] There are no tabs
[1103:259:0522/173510.065020:VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 1609648375
[1103:259:0522/173510.065031:VERBOSE1:inline_content_ad_handler.cc(138)] There are no orphaned inline content ad placements for tab id 1609648375
[1103:259:0522/173510.069908:VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for f2e89684-d7ac-44a7-a365-2e6ac0f723c8 placement ids

Confirm Browser did enter foreground appears in the log when the browser is foregrounded

[1162:259:0522/173613.040369:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did enter background appears in the log when the browser is backgrounded

[1162:259:0522/173614.821782:VERBOSE1:browser_manager.cc(76)] Browser did enter background

Confirm Browser did become active appears in the log when the browser becomes active

[1162:259:0522/173613.036851:VERBOSE1:browser_manager.cc(53)] Browser did become active

Confirm Browser did resign active appears in the log when the browser resigns active

[1162:259:0522/173614.819416:VERBOSE1:browser_manager.cc(53)] Browser did resign active

Confirm Browser did enter foreground, Browser did become active, Created tab with id # and Tab id # did become focused appear in the log when the browser is launched

[1103:259:0522/173450.613319:VERBOSE1:browser_manager.cc(53)] Browser did become active
[1103:259:0522/173450.613522:VERBOSE2:tab_manager.cc(248)] Created tab with id 1609648375
[1103:259:0522/173450.613607:VERBOSE2:tab_manager.cc(259)] Tab id 1609648375 did become focused
[1103:259:0522/173450.613848:VERBOSE2:tab_manager.cc(167)] Tab id 1609648375 HTML content changed
[1103:259:0522/173450.613860:VERBOSE1:conversions.cc(57)] Checking for conversions
[1103:259:0522/173450.613874:VERBOSE1:text_embedding_processor.cc(101)] chrome scheme is not supported for processing HTML content
[1103:259:0522/173450.613966:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did become active and Tab id # did become focused appear in the log when the browser is restored from being minimized

[1162:259:0522/174107.227377:VERBOSE1:browser_manager.cc(76)] Browser did enter foreground
[1162:259:0522/174107.243411:VERBOSE1:browser_manager.cc(53)] Browser did become active
[1162:259:0522/174107.781336:VERBOSE2:tab_manager.cc(259)] Tab id 1609648436 did become focused

Confirm Browser did resign active and Tab id # did become occluded appear in the log when the browser is minimized


[1162:259:0522/174108.832991:VERBOSE1:browser_manager.cc(53)] Browser did resign active
[1162:259:0522/174108.835230:VERBOSE2:tab_manager.cc(259)] Tab id 1609648436 did become occluded
[1162:259:0522/174108.842359:VERBOSE1:browser_manager.cc(76)] Browser did enter background

Sanity test with multiple browser windows

Logged #38427

media playing

``` [1162:259:0522/174321.907915:VERBOSE2:permission_rules.cc(263)] Media is playing [1162:259:0522/174321.908056:VERBOSE1:notification_ad_serving.cc(77)] Notification ad not served: Not allowed due to permission rules ```

@btlechowski
Copy link
Author

Verified on 1.66.113 on Lenovo TB-8506FS (Android 11.0)

Test plan from #38373 (comment)

Verified orphaned events were purged

18:53:50.874  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 752931928
18:53:50.892  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for ec047165-a267-45b0-ba84-11c6804b11b9 placement ids

Verified ad was served again

18:55:07.047  V  [VERBOSE1:eligible_inline_content_ads_v2.cc(39)] Get eligible inline content ads
18:55:07.054  V  [VERBOSE3:priority_util.h(21)] 1 untargeted ads with a priority of 51 in bucket 1
18:55:07.055  V  [VERBOSE1:eligible_inline_content_ads_v2.cc(132)] Predicted ad with creative instance id 1d87cb97-3f55-4a3d-bce1-1c841f39b6f8 and a priority of 51
18:55:07.055  V  [VERBOSE1:inline_content_ad_serving.cc(114)] Found 1 eligible ads
18:55:07.055  V  [VERBOSE1:inline_content_ad_serving.cc(120)] Chosen eligible ad with creative instance id 1d87cb97-3f55-4a3d-bce1-1c841f39b6f8 and a priority of 51
18:55:07.055  V  [VERBOSE1:inline_content_ad_handler.cc(125)] Cached inline content ad with placement id 8595a9d2-e66c-4f34-ab2e-296566393bfd and tab id 752931930
18:55:07.055  V  [VERBOSE1:inline_content_ad_handler.cc(186)] Served inline content ad:
                   placementId: 8595a9d2-e66c-4f34-ab2e-296566393bfd
                   creativeInstanceId: 1d87cb97-3f55-4a3d-bce1-1c841f39b6f8
                   creativeSetId: 59ae2407-51ae-48f6-9d67-6ae234319181
                   campaignId: 07de7f05-ab32-4af0-a350-a1bce4427eac
                   advertiserId: 93130af3-2def-4ecb-b836-b3772e73b3c9
                   segment: untargeted
                   title: [Staging] Aspect Ratio
                   description: Test Aspect Ratio
                   imageUrl: https://pcdn.bravesoftware.com/brave-news-ads/0f61aa5e-d79f-4585-9835-b75afb3343b0.jpg.pad
                   dimensions: 900x750
                   ctaText: Aspect Ratio
                   targetUrl: https://brave.com/careers/
18:55:07.074  V  [VERBOSE3:inline_content_ad_handler.cc(193)] Served inline content ad impression with placement id 8595a9d2-e66c-4f34-ab2e-296566393bfd and creative instance id 1d87cb97-3f55-4a3d-bce1-1c841f39b6f8

Test plan from brave/brave-core#23720

Confirm Tab id # did change appears in the log when navigating to a new URL

18:55:53.590  V  [VERBOSE2:tab_manager.cc(253)] Tab id 752931930 did change

Confirm Created tab with id # and Tab id # did become focused appear in the log when opening a new tab

18:56:33.002  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 0B (0:0:900 s)
18:56:33.002  V  [VERBOSE2:tab_manager.cc(248)] Created tab with id 752931931
18:56:33.003  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 0D (0:0:900 s)
18:56:33.003  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931931 did become focused

Confirm Restored focused tab with id # appear in the log when restoring a tab, i.e., after relaunching the browser

18:59:59.578  V  [VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 752931983
19:02:00.233  V  [VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 752931984

Confirm Tab id # did become focused appears in the log when focusing on an existing tab

19:02:33.940  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931984 did become occluded
19:02:33.942  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:02:33.942  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931983 did become focused
19:02:33.943  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:02:35.612  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931983 did become occluded
19:02:35.615  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:02:35.615  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931984 did become focused

Confirm Tab id # did become occluded appears in the log when a tab becomes inactive.

19:02:33.940  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931984 did become occluded
19:02:33.942  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:02:33.942  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931983 did become focused
19:02:33.943  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:02:35.612  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931983 did become occluded
19:02:35.615  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:02:35.615  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931984 did become focused

Confirm Tab id # did become occluded and Tab id # was closed appear in the log when closing a tab

19:03:15.341  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931984 did become occluded
19:03:15.343  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:03:15.343  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752931983 did become focused
19:03:15.368  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:03:18.370  I  Killing 32424:com.brave.browser:sandboxed_process0:org.chromium.content.app.SandboxedProcessService0:3/u0a308i-8897 (adj 0): isolated not needed
19:03:18.374  V  [VERBOSE2:tab_manager.cc(265)] Tab id 752931984 was closed

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the last tab

Not applicable to Android. After closing last tab the browser window is still shown

Confirm Created tab with id # and Tab id # did become focused appear in the log when launching the browser after closing the last tab

Not applicable to Android. After closing last tab the browser window is still shown

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the browser window

19:08:37.964  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752932039 did become occluded
19:08:37.982  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 09 (0:0:900 s)
19:08:37.982  V  [VERBOSE2:tab_manager.cc(265)] Tab id 752932039 was closed
19:08:37.983  V  [VERBOSE2:tab_manager.cc(95)] There are no tabs
19:08:37.984  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 08 (0:0:900 s)
19:08:37.984  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 752932039
19:08:37.985  V  [VERBOSE1:inline_content_ad_handler.cc(138)] There are no orphaned inline content ad placements for tab id 752932039

Confirm Restored focused tab with id # appear in the log when launching the browser after closing the browser window

19:11:41.593  V  [VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 752932091

Confirm Purging orphaned inline content ad placements for tab id # and Purged orphaned inline content ad events for ... placement ids appear in the log when closing at tab with a served inline content ad

19:13:30.494  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 752932092
19:13:30.507  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for c8d0a9a0-5375-4d20-be64-f31a64f5e8e3 placement ids

Confirm Purging orphaned inline content ad placements for tab id # and There are no orphaned inline content ad placements for tab id # do not appear in the log when closing a tab with a viewed inline content ad

Log states events are purged:

19:15:13.213  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 752932093
19:15:13.215  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for a56e5943-6793-465e-9b2a-5c323326e4b7 placement ids

Logged #38425

Confirm orphaned inline content ads are purged when launching the browser

19:15:13.213  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 752932093
19:15:13.215  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for a56e5943-6793-465e-9b2a-5c323326e4b7 placement ids

Confirm Browser did enter foreground appears in the log when the browser is foregrounded

19:16:23.270  V  [VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did enter background appears in the log when the browser is backgrounded

19:15:57.434  V  [VERBOSE1:browser_manager.cc(76)] Browser did enter background

Confirm Browser did become active appears in the log when the browser becomes active

19:16:23.368  V  [VERBOSE1:browser_manager.cc(53)] Browser did become active

Confirm Browser did resign active appears in the log when the browser resigns active

19:15:57.432  V  [VERBOSE1:browser_manager.cc(53)] Browser did resign active

Confirm Browser did enter foreground, Browser did become active, Created tab with id # and Tab id # did become focused appear in the log when the browser is launched

Not testable on Android as not able to get clean profile with flags.

Confirm Browser did become active and Tab id # did become focused appear in the log when the browser is restored from being minimized

19:16:23.269  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752932091 did become focused
19:16:23.270  V  [VERBOSE1:browser_manager.cc(76)] Browser did enter foreground
19:16:23.368  V  [VERBOSE1:browser_manager.cc(53)] Browser did become active

Confirm Browser did resign active and Tab id # did become occluded appear in the log when the browser is minimized


19:15:57.432  V  [VERBOSE1:browser_manager.cc(53)] Browser did resign active
19:15:57.433  V  [VERBOSE6:user_activity_manager.cc(42)] Triggered event: 17 (0:0:900 s)
19:15:57.434  V  [VERBOSE1:browser_manager.cc(76)] Browser did enter background
19:15:57.581  V  [VERBOSE2:tab_manager.cc(259)] Tab id 752932091 did become occluded

media playing

``` 19:23:23.613 V [VERBOSE2:permission_rules.cc(263)] Media is playing 19:23:23.613 V [VERBOSE1:notification_ad_serving.cc(77)] Notification ad not served: Not allowed due to permission rules ```

@btlechowski
Copy link
Author

Verified on 1.66.113 on Pixel 7 Pro (Android 14.0)

Test plan from #38373 (comment)

Verified orphaned events were purged

20:37:11.143  V  [VERBOSE2:tab_manager.cc(265)] Tab id 368340216 was closed
20:37:11.143  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 368340216
20:37:11.154  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 695de5f6-ebdf-4984-915e-3b5a7162ab90 placement ids

Verified ad was served again

20:37:56.083  V  [VERBOSE1:inline_content_ad_handler.cc(164)] Opportunity arose to serve an inline content ad
20:37:56.083  V  [VERBOSE1:text_classification_model.cc(78)] No text classification probabilities found for en-US locale
20:37:56.083  V  [VERBOSE1:eligible_inline_content_ads_v2.cc(39)] Get eligible inline content ads
20:37:56.085  V  [VERBOSE3:priority_util.h(21)] 1 untargeted ads with a priority of 51 in bucket 1
20:37:56.085  V  [VERBOSE1:eligible_inline_content_ads_v2.cc(132)] Predicted ad with creative instance id 1d87cb97-3f55-4a3d-bce1-1c841f39b6f8 and a priority of 51
20:37:56.085  V  [VERBOSE1:inline_content_ad_serving.cc(114)] Found 1 eligible ads
20:37:56.086  V  [VERBOSE1:inline_content_ad_serving.cc(120)] Chosen eligible ad with creative instance id 1d87cb97-3f55-4a3d-bce1-1c841f39b6f8 and a priority of 51
20:37:56.086  V  [VERBOSE1:inline_content_ad_handler.cc(125)] Cached inline content ad with placement id 6e3c113a-ba10-4809-9b47-1fd7c28aa1b8 and tab id 368340218
20:37:56.086  V  [VERBOSE1:inline_content_ad_handler.cc(186)] Served inline content ad:
                   placementId: 6e3c113a-ba10-4809-9b47-1fd7c28aa1b8
                   creativeInstanceId: 1d87cb97-3f55-4a3d-bce1-1c841f39b6f8
                   creativeSetId: 59ae2407-51ae-48f6-9d67-6ae234319181
                   campaignId: 07de7f05-ab32-4af0-a350-a1bce4427eac
                   advertiserId: 93130af3-2def-4ecb-b836-b3772e73b3c9
                   segment: untargeted
                   title: [Staging] Aspect Ratio
                   description: Test Aspect Ratio
                   imageUrl: https://pcdn.bravesoftware.com/brave-news-ads/0f61aa5e-d79f-4585-9835-b75afb3343b0.jpg.pad
                   dimensions: 900x750
                   ctaText: Aspect Ratio
                   targetUrl: https://brave.com/careers/
20:37:56.091  V  [VERBOSE3:inline_content_ad_handler.cc(193)] Served inline content ad impression with placement id 6e3c113a-ba10-4809-9b47-1fd7c28aa1b8 and creative instance id 1d87cb97-3f55-4a3d-bce1-1c841f39b6f8

Test plan from brave/brave-core#23720

Confirm Tab id # did change appears in the log when navigating to a new URL

20:38:34.077  V  [VERBOSE2:tab_manager.cc(253)] Tab id 368340218 did change

Confirm Created tab with id # and Tab id # did become focused appear in the log when opening a new tab

20:39:14.641  V  [VERBOSE2:tab_manager.cc(248)] Created tab with id 368340219
20:39:14.645  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340219 did become focused
20:39:14.652  V  [VERBOSE2:tab_manager.cc(167)] Tab id 368340219 HTML content changed

Confirm Restored focused tab with id # appear in the log when restoring a tab, i.e., after relaunching the browser

20:40:50.971  V  [VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 368340324

Confirm Tab id # did become focused appears in the log when focusing on an existing tab

20:41:47.764  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340325 did become occluded
20:41:48.193  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340324 did become focused
20:41:55.004  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340324 did become occluded
20:41:55.546  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340325 did become focused

Confirm Tab id # did become occluded appears in the log when a tab becomes inactive.

20:41:47.764  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340325 did become occluded
20:41:48.193  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340324 did become focused
20:41:55.004  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340324 did become occluded
20:41:55.546  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340325 did become focused

Confirm Tab id # did become occluded and Tab id # was closed appear in the log when closing a tab

20:42:41.624  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340325 did become occluded
20:42:43.781  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340324 did become focused
20:42:46.810  I  Killing 26386:com.brave.browser:sandboxed_process0:org.chromium.content.app.SandboxedProcessService0:3/u0a270i-8997 (adj 0): isolated not needed
20:42:46.817  V  [VERBOSE2:tab_manager.cc(265)] Tab id 368340325 was closed

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the last tab

Not applicable to Android. After closing last tab the browser window is still shown

Confirm Created tab with id # and Tab id # did become focused appear in the log when launching the browser after closing the last tab

Not applicable to Android. After closing last tab the browser window is still shown

Confirm Tab id # did become occluded, Tab id # was closed and There are no tabs appear in the log when closing the browser window

20:43:39.881  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340330 did become occluded
20:43:39.884  V  [VERBOSE2:tab_manager.cc(265)] Tab id 368340330 was closed
20:43:39.884  V  [VERBOSE2:tab_manager.cc(95)] There are no tabs
20:43:39.884  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 368340330
20:43:39.895  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 17ec2217-bc37-448b-944d-325d3caefa7b placement ids

Confirm Restored focused tab with id # appear in the log when launching the browser after closing the browser window

20:40:50.971  V  [VERBOSE2:tab_manager.cc(243)] Restored focused tab with id 368340324

Confirm Purging orphaned inline content ad placements for tab id # and Purged orphaned inline content ad events for ... placement ids appear in the log when closing at tab with a served inline content ad

20:37:11.143  V  [VERBOSE2:tab_manager.cc(265)] Tab id 368340216 was closed
20:37:11.143  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 368340216
20:37:11.154  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 695de5f6-ebdf-4984-915e-3b5a7162ab90 placement ids

Confirm Purging orphaned inline content ad placements for tab id # and There are no orphaned inline content ad placements for tab id # do not appear in the log when closing a tab with a viewed inline content ad

Log states events are purged:

19:15:13.213  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 752932093
19:15:13.215  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for a56e5943-6793-465e-9b2a-5c323326e4b7 placement ids

Logged #38425

Confirm orphaned inline content ads are purged when launching the browser

20:37:11.143  V  [VERBOSE1:inline_content_ad_handler.cc(133)] Purging orphaned inline content ad placements for tab id 368340216
20:37:11.154  V  [VERBOSE1:inline_content_ad_handler.cc(156)] Purged orphaned inline content ad events for 695de5f6-ebdf-4984-915e-3b5a7162ab90 placement ids

Confirm Browser did enter foreground appears in the log when the browser is foregrounded

20:46:31.292  V  [VERBOSE1:browser_manager.cc(76)] Browser did enter foreground

Confirm Browser did enter background appears in the log when the browser is backgrounded

20:46:15.855  V  [VERBOSE1:browser_manager.cc(76)] Browser did enter background

Confirm Browser did become active appears in the log when the browser becomes active

20:46:31.292  V  [VERBOSE1:browser_manager.cc(53)] Browser did become active

Confirm Browser did resign active appears in the log when the browser resigns active

20:46:15.816  V  [VERBOSE1:browser_manager.cc(53)] Browser did resign active

Confirm Browser did enter foreground, Browser did become active, Created tab with id # and Tab id # did become focused appear in the log when the browser is launched

Not testable on Android as not able to get clean profile with flags.

Confirm Browser did become active and Tab id # did become focused appear in the log when the browser is restored from being minimized

20:48:30.196  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340434 did become focused
20:48:30.196  V  [VERBOSE1:browser_manager.cc(76)] Browser did enter foreground
20:48:30.212  V  [VERBOSE1:browser_manager.cc(53)] Browser did become active

Confirm Browser did resign active and Tab id # did become occluded appear in the log when the browser is minimized


20:48:28.059  V  [VERBOSE1:browser_manager.cc(53)] Browser did resign active
20:48:28.060  V  [VERBOSE1:browser_manager.cc(76)] Browser did enter background
20:48:28.136  V  [VERBOSE2:tab_manager.cc(259)] Tab id 368340434 did become occluded

media playing

``` 20:52:00.193 V [VERBOSE2:permission_rules.cc(263)] Media is playing 20:52:00.193 V [VERBOSE1:notification_ad_serving.cc(77)] Notification ad not served: Not allowed due to permission rules ```

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@tmancey tmancey

Labels
feature/ads OS/Android Fixes related to Android browser functionality OS/Desktop priority/P1 A very extremely bad problem. We might push a hotfix for it. QA Pass - Android ARM QA Pass - Android Tab QA Pass-Linux QA Pass-macOS QA Pass-Win64 QA/Test-All-Platforms QA/Yes regression release-notes/exclude
Projects
Ads
  
Done
Milestone
1.66.x - Release #2
Development

Successfully merging a pull request may close this issue.

[ads] Fixes brave News Inline orphaned ad events are not purged brave/brave-core
4 participants
@tmancey @kjozwiak @btlechowski @brave-builds