Fix chttpd auth cache log errors #1950

jaydoane · 2019-02-27T21:05:04Z

Overview

In situations where the chttpd authenticaion db (usually named "_users")
does not get created, or gets deleted, the auth cache still attempts
to start the change listener, which results in notice and error level
logs in the system like:

[notice] 2018-12-03T22:04:44.299392Z node1@127.0.0.1 <0.374.0> -------- chttpd_auth_cache changes listener died database_does_not_exist at mem3_shards:load_shards_from_db/6(line:395) <= mem3_shards:load_shards_from_disk/1(line:370) <= mem3_shards:load_shards_from_disk/2(line:399) <= mem3_shards:for_docid/3(line:86) <= fabric_doc_open:go/3(line:39) <= chttpd_auth_cache:ensure_auth_ddoc_exists/2(line:195) <= chttpd_auth_cache:listen_for_changes/1(line:142)

[error] 2018-12-03T22:04:44.299585Z node1@127.0.0.1 emulator -------- Error in process <0.3180.0> on node 'node1@127.0.0.1' with exit value:
{database_does_not_exist,[{mem3_shards,load_shards_from_db,"_users",[{file,"src/mem3_shards.erl"},{line,395}]},{mem3_shards,load_shards_from_disk,1,[{file,"src/mem3_shards.erl"},{line,370}]},{mem3_shards,load_shards_from_disk,2,[{file,"src/mem3_shards.erl"},{line,399}]},{mem3_shards,for_docid,3,[{file,"src/mem3_shards.erl"},{line,86}]},{fabric_doc_open,go,3,[{file,"src/fabric_doc_open.erl"},{line,39}]},{chttpd_auth_cache,ensure_auth_ddoc_exists,2,[{file,"src/chttpd_auth_cache.erl"},{line,195}]},{chttpd_auth_cache,listen_for_changes,1,[{file,"src/chttpd_auth_cache.erl"},{line,142}]}]}

This changes the auth cache so that it

• Only starts change listener if auth db exists
• Only retains EndSeq if auth db still exists

Fixes #1354
Fixes #1949

Testing recommendations

make eunit apps=chttpd suites=chttpd_auth_cache_test

Related Issues or Pull Requests

Checklist

Code is written and works correctly;
Changes are covered by tests;
Documentation reflects the changes;

In situations where the chttpd authenticaion db (usually named "_users") does not get created, or gets deleted, the auth cache still attempts to start the change listener, which results in notice and error level logs in the system like: [notice] 2018-12-03T22:04:44.299392Z node1@127.0.0.1 <0.374.0> -------- chttpd_auth_cache changes listener died database_does_not_exist at mem3_shards:load_shards_from_db/6(line:395) <= mem3_shards:load_shards_from_disk/1(line:370) <= mem3_shards:load_shards_from_disk/2(line:399) <= mem3_shards:for_docid/3(line:86) <= fabric_doc_open:go/3(line:39) <= chttpd_auth_cache:ensure_auth_ddoc_exists/2(line:195) <= chttpd_auth_cache:listen_for_changes/1(line:142) [error] 2018-12-03T22:04:44.299585Z node1@127.0.0.1 emulator -------- Error in process <0.3180.0> on node 'node1@127.0.0.1' with exit value: {database_does_not_exist,[{mem3_shards,load_shards_from_db,"_users",[{file,"src/mem3_shards.erl"},{line,395}]},{mem3_shards,load_shards_from_disk,1,[{file,"src/mem3_shards.erl"},{line,370}]},{mem3_shards,load_shards_from_disk,2,[{file,"src/mem3_shards.erl"},{line,399}]},{mem3_shards,for_docid,3,[{file,"src/mem3_shards.erl"},{line,86}]},{fabric_doc_open,go,3,[{file,"src/fabric_doc_open.erl"},{line,39}]},{chttpd_auth_cache,ensure_auth_ddoc_exists,2,[{file,"src/chttpd_auth_cache.erl"},{line,195}]},{chttpd_auth_cache,listen_for_changes,1,[{file,"src/chttpd_auth_cache.erl"},{line,142}]}]} This changes the auth cache so that it • Only starts change listener if auth db exists • Only retains EndSeq if auth db still exists Fixes apache#1354 Fixes apache#1949

wohali · 2019-03-02T19:11:35Z

@jaydoane One unintended side effect of this is that there is no logged warning that the system databases are missing anymore. We should log an error once at least.

janl · 2019-03-04T10:15:35Z

+1 for at least one log

iilyak · 2019-03-04T11:41:09Z

src/chttpd/test/chttpd_auth_cache_test.erl

+
+change_listener_should_not_start_if_auth_db_missing(_DbName) ->
+    ?_test(begin
+        %% ok = restart_app(chttpd),


commented line

iilyak · 2019-03-04T11:43:44Z

src/chttpd/test/chttpd_auth_cache_test.erl

+
+change_listener_should_start_if_auth_db_exists(DbName) ->
+    ?_test(begin
+        config:set("chttpd_auth", "authentication_db", ?b2l(DbName), false),


config updates need to be moved into setup/teardown. Otherwise we might have the config set for subsequent tests when the current one fails.

iilyak · 2019-03-04T11:49:08Z

src/chttpd/test/chttpd_auth_cache_test.erl

+                foreach,
+                fun setup/0, fun teardown/1,
+                [
+                    fun change_listener_should_not_start_if_auth_db_missing/1,


I think we are not covering all possible scenarios:

change_listener_starts_after_auth_db_created

change_listener_stops_and_not_restarted_after_auth_db_deleted

iilyak · 2019-03-04T11:50:03Z

src/chttpd/src/chttpd_auth_cache.erl

-handle_info({start_listener, Seq}, State) ->
-    {noreply, State#state{changes_pid = spawn_changes(Seq)}};
+    erlang:send_after(5000, self(), {maybe_start_listener, Seq}),
+    {noreply, State#state{last_seq = Seq, changes_pid = undefined}};


Nice catch with missing changes_pid = undefined in previous version of the code.

wohali · 2020-10-09T15:55:17Z

@jaydoane any plans to get this in? I am preparing to mass-close old PRs that never got merged.

jaydoane · 2020-10-12T21:01:15Z

@jaydoane any plans to get this in? I am preparing to mass-close old PRs that never got merged.

@wohali oh no, I completely forgot about this one 🙀

It seems like the main issues left are including more test cases, and adding some logging for missing _users db? If there's general agreement that this is a desirable PR, I'm happy to make those changes and get it finished.

wohali · 2020-10-12T21:37:26Z

Yes please.

jaydoane · 2021-01-05T05:39:16Z

I took another look at this, but noticed this commit from Jan already addressed the issue of stack traces in the logs, and the repeating error does actually seem like a good -- albeit somewhat spammy -- feature. So I think we should just close this in favor of his more elegant fix.

jaydoane mentioned this pull request Feb 27, 2019

couchdb spams the logs every 5 seconds when started for the first time due to no _users db #1949

Closed

jaydoane force-pushed the fix-chttpd_auth_cache-log-errors branch from 0b490f3 to 8f2f436 Compare March 2, 2019 18:45

jaydoane marked this pull request as ready for review March 2, 2019 18:49

iilyak reviewed Mar 4, 2019

View reviewed changes

WIP

ca1ee32

wohali changed the base branch from master to main October 21, 2020 18:19

jaydoane force-pushed the fix-chttpd_auth_cache-log-errors branch from 2e70e6e to 8f2f436 Compare October 26, 2020 04:05

jaydoane changed the base branch from main to 3.x December 14, 2020 21:40

jaydoane changed the base branch from 3.x to main December 14, 2020 21:40

jaydoane closed this Jan 5, 2021

jaydoane deleted the fix-chttpd_auth_cache-log-errors branch January 8, 2021 04:24

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix chttpd auth cache log errors #1950

Fix chttpd auth cache log errors #1950

jaydoane commented Feb 27, 2019 •

edited

Loading

wohali commented Mar 2, 2019

janl commented Mar 4, 2019

iilyak Mar 4, 2019

iilyak Mar 4, 2019

iilyak Mar 4, 2019

iilyak Mar 4, 2019

wohali commented Oct 9, 2020

jaydoane commented Oct 12, 2020

wohali commented Oct 12, 2020

jaydoane commented Jan 5, 2021

Fix chttpd auth cache log errors #1950

Fix chttpd auth cache log errors #1950

Conversation

jaydoane commented Feb 27, 2019 • edited Loading

Overview

Testing recommendations

Related Issues or Pull Requests

Checklist

wohali commented Mar 2, 2019

janl commented Mar 4, 2019

iilyak Mar 4, 2019

Choose a reason for hiding this comment

iilyak Mar 4, 2019

Choose a reason for hiding this comment

iilyak Mar 4, 2019

Choose a reason for hiding this comment

iilyak Mar 4, 2019

Choose a reason for hiding this comment

wohali commented Oct 9, 2020

jaydoane commented Oct 12, 2020

wohali commented Oct 12, 2020

jaydoane commented Jan 5, 2021

jaydoane commented Feb 27, 2019 •

edited

Loading